© Jesper Wisborg Krogh 2020
J. W. KroghMySQL 8 Query Performance Tuninghttps://doi.org/10.1007/978-1-4842-5584-1_20

20. Analyzing Queries

Jesper Wisborg Krogh1 
(1)
Hornsby, NSW, Australia
 

In the previous chapter, you learned how to find queries that are candidates for optimization. It is now time to take the next step – analyzing the queries to determine why they do not perform as expected. The main tool during the analysis is the EXPLAIN statement which shows the query plan the optimizer will use. Related is the optimizer trace that can be used to investigate why the optimizer ended up with the query plan. Another possibility is to use the statement and stage information in the Performance Schema to see where a stored procedure or a query spends the most time. These three topics will be discussed in this chapter.

The discussion of the EXPLAIN statement is by far the largest part of this chapter and has been split into four sections:
  • EXPLAIN Usage: The basic usage of the EXPLAIN statement.

  • EXPLAIN Formats: The details specific to each of the formats that the query plan can be viewed in. This includes both formats explicitly chosen with the EXPLAIN statement and Visual Explain used by MySQL Workbench.

  • EXPLAIN Output: A discussion of the information available in the query plans.

  • EXPLAIN Examples: Some examples of using the EXPLAIN statement with a discussion of the data returned.

EXPLAIN Usage

The EXPLAIN statement returns an overview of the query plan the MySQL optimizer will use for a given query. It is at the same time very simple and one of the more complex tools in query tuning. It is simple, because you just need to add the EXPLAIN command before the query you want to investigate, and complex because understanding the information requires some understanding of how MySQL and its optimizer work. You can use EXPLAIN both with a query you explicitly specify and with a query currently being executed by another connection. This section goes through the basic usage of the EXPLAIN statement.

Usage for Explicit Queries

You generate the query plan for a query by adding EXPLAIN in front of the query, optionally adding the FORMAT option to specify whether you want the result returned in a traditional table format, using the JSON format, or in a tree-style format. There is support for SELECT, DELETE, INSERT, REPLACE, and UPDATE statements. The query is not executed (but see the next subsection about EXPLAIN ANALYZE for an exception), so it is safe to obtain the query plan.

If you need to analyze composite queries such as stored procedures and stored functions, you will need first to split the execution out into individual queries and then use EXPLAIN for each of the queries that should be analyzed. One method to determine the individual queries in a stored program is to use the Performance Schema. An example of achieving this will be shown later in this chapter.

The simplest use of EXPLAIN is just to specify EXPLAIN with the query that you want to analyze:
mysql> EXPLAIN <query>;
In the example, <query> is the query you want to analyze. Using the EXPLAIN statement without the FORMAT option returns the result in the traditional table format. If you want to specify the format, you can do so by adding FORMAT=TRADITIONAL|JSON|TREE:
mysql> EXPLAIN FORMAT=TRADITIONAL <query>
mysql> EXPLAIN FORMAT=JSON <query>
mysql> EXPLAIN FORMAT=TREE <query>

Which format that is the preferred depends on your needs. The traditional format is easier to use when you need an overview of the query plan, the indexes used, and other basic information about the query plan. The JSON format provides more details and is easier for an application to use. For example, Visual Explain in MySQL Workbench uses the JSON-formatted output.

The tree format is the newest format and supported in MySQL 8.0.16 and later. It requires the query to be executed using the Volcano iterator executor which at the time of writing is not supported for all queries. A special use of the tree format is for the EXPLAIN ANALYZE statement.

EXPLAIN ANALYZE

The EXPLAIN ANALYZE statement 1 is new as of MySQL 8.0.18 and is an extension of the standard EXPLAIN statement using the tree format. The key difference is that EXPLAIN ANALYZE actually executes the query and, while executing it, statistics for the execution are collected. While the statement is executed, the output from the query is suppressed so only the query plan and statistics are returned. Like for the tree output format, it is required that the Volcano iterator executor is used.

Note

At the time of writing, the requirement on the Volcano iterator executor limits the queries you can use EXPLAIN ANALYZE with to a subset of SELECT statements. It is expected that the range of supported queries will increase over time.

The usage of EXPLAIN ANALYZE is very similar to what you have already seen for the EXPLAIN statement:
mysql> EXPLAIN ANALYZE <query>

The output of EXPLAIN ANALYZE will be discussed together with the tree format output later in this chapter.

By nature, EXPLAIN ANALYZE only works with an explicit query as it is required to monitor the query from start to finish. The plain EXPLAIN statement on the other hand can also be used for ongoing queries.

Usage for Connections

Imagine you are investigating an issue with poor performance and you notice there is a query that has been running for several hours. You know this is not supposed to happen, so you want to analyze why the query is so slow. One option is to copy the query and execute EXPLAIN for it. However, this may not provide the information you need as the index statistics may have changed since the slow query started, and thus analyzing the query now does not show the actual query plan causing the slow performance.

A better solution is to request the actual query plan used for the slow query. You can get that using the EXPLAIN FOR CONNECTION variant of the EXPLAIN statement. If you want to try it, you need a long-running query, for example:
SELECT * FROM world.city WHERE id = 130 + SLEEP(0.1);

This will take around 420 seconds (0.1 second per row in the world.city table).

You will need the connection id of the query you want to investigate and pass this as an argument to EXPLAIN. You can get the connection id from the process list information. For example, if you use the sys.session view, the connection id can be found in the conn_id column:
mysql> SELECT conn_id, current_statement,
              statement_latency
         FROM sys.session
        WHERE command = 'Query'
        ORDER BY time
         DESC LIMIT 1G
*************************** 1. row ***************************
          conn_id: 8
current_statement: SELECT * FROM world.city WHERE id = 130 + SLEEP(0.1)
statement_latency: 4.22 m
1 row in set (0.0551 sec)
In order to keep the output simple, it has been limited to the connection of interest for this example. The connection id for the query is 8. You can use this to get the execution plan for the query as follows:
mysql> EXPLAIN FOR CONNECTION 8G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: city
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 4188
     filtered: 100
        Extra: Using where
1 row in set (0.0004 sec)

You can optionally add which format you want in the same way as when you explicitly specify a query. The filtered column may show 100.00 if you are using a different client than MySQL Shell. Before discussing what the output means, it is worth familiarizing yourself with the output formats.

EXPLAIN Formats

You can choose between several formats when you need to examine the query plans. Which one you choose mostly depends on your preferences. That said, the JSON format does include more information than the traditional and tree formats. If you prefer a visual representation of the query plan, Visual Explain from MySQL Workbench is a great option.

This section will discuss each format and show the output for the query plan of the following query:
SELECT ci.ID, ci.Name, ci.District,
       co.Name AS Country, ci.Population
  FROM world.city ci
       INNER JOIN
         (SELECT Code, Name
            FROM world.country
           WHERE Continent = 'Europe'
           ORDER BY SurfaceArea
           LIMIT 10
         ) co ON co.Code = ci.CountryCode
 ORDER BY ci.Population DESC
 LIMIT 5;

The query finds the five largest cities across the ten smallest countries by area in Europe and orders them by the city population in descending order. The reason for choosing this query is that it shows how the various output formats represent subqueries, ordering, and limits. The information returned by the EXPLAIN statements will not be discussed in this section; that is deferred to the “EXPLAIN Examples” section.

Note

The output of EXPLAIN statements depends on the settings of the optimizer switches, the index statistics, and the values in the mysql.engine_cost and mysql.server_cost tables, so you may not see the same as in the examples. The example outputs have been used with the default values and a freshly loaded world sample database with ANALYZE TABLE executed for the tables after the load has completed, and they have been created in MySQL Shell where warnings are fetched automatically by default (but the warnings are only included in the output when they are discussed). If you are not using MySQL Shell, you will have to execute SHOW WARNINGS to retrieve the warnings.

The query plan outputs are quite verbose. To make it easier to compare the outputs, the examples in this section have been combined with the result of the query into the file explain_formats.txt in this book’s GitHub repository. For the tree output format (including for EXPLAIN ANALYZE), an extra new line has been added between the column name and the query plan to get the tree hierarchy displaying clearer:
*************************** 1. row ***************************
EXPLAIN:
-> Limit: 5 row(s)
    -> Sort: <temporary>.Population DESC, limit input to 5 row(s) per chunk
Instead of:
*************************** 1. row ***************************
EXPLAIN: -> Limit: 5 row(s)
    -> Sort: <temporary>.Population DESC, limit input to 5 row(s) per chunk

This convention is used throughout the chapter.

Traditional Format

When you execute the EXPLAIN command without the FORMAT argument or with the format set to TRADITIONAL , the output is returned as a table as if you had queried a normal table. This is useful when you want an overview of the query plan and it is a human database administrator or developer who examines the output.

Tip

The table output can be quite wide particularly if there are many partitions, several possible indexes that can be used, or several pieces of extra information. You can request to get the output in a vertical format by using the --vertical option when you invoke the mysql command-line client, or you can use G to terminate the query.

There are 12 columns in the output. If a field does not have any value, NULL is used. The meaning of each column will be discussed in the next section. Listing 20-1 shows the traditional output for the example query.
mysql> EXPLAIN FORMAT=TRADITIONAL
       SELECT ci.ID, ci.Name, ci.District,
              co.Name AS Country, ci.Population
         FROM world.city ci
              INNER JOIN
                (SELECT Code, Name
                   FROM world.country
                  WHERE Continent = 'Europe'
                  ORDER BY SurfaceArea
                  LIMIT 10
                ) co ON co.Code = ci.CountryCode
        ORDER BY ci.Population DESC
        LIMIT 5G
*************************** 1. row ***************************
           id: 1
  select_type: PRIMARY
        table: <derived2>
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 10
     filtered: 100
        Extra: Using temporary; Using filesort
*************************** 2. row ***************************
           id: 1
  select_type: PRIMARY
        table: ci
   partitions: NULL
         type: ref
possible_keys: CountryCode
          key: CountryCode
      key_len: 3
          ref: co.Code
         rows: 18
     filtered: 100
        Extra: NULL
*************************** 3. row ***************************
           id: 2
  select_type: DERIVED
        table: country
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 239
     filtered: 14.285715103149414
        Extra: Using where; Using filesort
3 rows in set, 1 warning (0.0089 sec)
Note (code 1003): /* select#1 */ select `world`.`ci`.`ID` AS `world`.`ci`.`Name` AS `Name`,`world`.`ci`.`District` AS `District`,`co`.`Name` AS `Country`,`world`.`ci`.`Population` AS `Population` from `world`.`city` `ci` join (/* select#2 */ select `world`.`country`.`Code` AS `Code`,`world`.`country`.`Name` AS `Name` from `world`.`country` where (`world`.`country`.`Continent` = 'Europe') order by `world`.`country`.`SurfaceArea` limit 10) `co` where (`world`.`ci`.`CountryCode` = `co`.`Code`) order by `world`.`ci`.`Population` desc limit 5
Listing 20-1

Example of the traditional EXPLAIN output

Notice how the first table is called <derived 2>. This is for the subquery on the country table, and the number 2 refers to the value of the id column where the subquery is executed. The Extra column contains information such as whether the query uses a temporary table and a file sort. At the end of the output is the query after the optimizer has rewritten it. In many cases there are not many changes, but in some cases the optimizer may be able to make significant changes to the query. In the rewritten query, notice how a comment, for example, /* select#1 */, is used to show which id value is used for that part of the query. There may be other hints in the rewritten query to tell how the query is executed. The rewritten query is returned as a note by SHOW WARNINGS (by default, executed implicitly by MySQL Shell).

The output can seem overwhelming, and it can be hard to understand how the information can be used to analyze queries. Once the other output formats, the detailed information for the select types and join types, and the extra information have been discussed, there will be some examples where the EXPLAIN information will be used.

What do you do if you want to analyze the query plan programmatically? You can handle the EXPLAIN output like that of a normal SELECT query – or you can request the information in the JSON format which includes some additional information.

JSON Format

Since MySQL 5.6, it has been possible to request the EXPLAIN output using the JSON format. One advantage of the JSON format over the traditional table format is that the added flexibility of the JSON format has been used to group the information in a more logical way.

The basic concept in the JSON output is a query block. The query block defines a part of the query and may in turn include query blocks of its own. This allows MySQL to specify the details of the query execution to the query block they belong. This is also visible from the output of the example query that is shown in Listing 20-2.
mysql> EXPLAIN FORMAT=JSON
       SELECT ci.ID, ci.Name, ci.District,
              co.Name AS Country, ci.Population
         FROM world.city ci
              INNER JOIN
                (SELECT Code, Name
                   FROM world.country
                  WHERE Continent = 'Europe'
                  ORDER BY SurfaceArea
                  LIMIT 10
                ) co ON co.Code = ci.CountryCode
        ORDER BY ci.Population DESC
        LIMIT 5G
*************************** 1. row ***************************
EXPLAIN: {
  "query_block": {
    "select_id": 1,
    "cost_info": {
      "query_cost": "247.32"
    },
    "ordering_operation": {
      "using_temporary_table": true,
      "using_filesort": true,
      "cost_info": {
        "sort_cost": "180.52"
      },
      "nested_loop": [
        {
          "table": {
            "table_name": "co",
            "access_type": "ALL",
            "rows_examined_per_scan": 10,
            "rows_produced_per_join": 10,
            "filtered": "100.00",
            "cost_info": {
              "read_cost": "2.63",
              "eval_cost": "1.00",
              "prefix_cost": "3.63",
              "data_read_per_join": "640"
            },
            "used_columns": [
              "Code",
              "Name"
            ],
            "materialized_from_subquery": {
              "using_temporary_table": true,
              "dependent": false,
              "cacheable": true,
              "query_block": {
                "select_id": 2,
                "cost_info": {
                  "query_cost": "25.40"
                },
                "ordering_operation": {
                  "using_filesort": true,
                  "table": {
                    "table_name": "country",
                    "access_type": "ALL",
                    "rows_examined_per_scan": 239,
                    "rows_produced_per_join": 34,
                    "filtered": "14.29",
                    "cost_info": {
                      "read_cost": "21.99",
                      "eval_cost": "3.41",
                      "prefix_cost": "25.40",
                      "data_read_per_join": "8K"
                    },
                    "used_columns": [
                      "Code",
                      "Name",
                      "Continent",
                      "SurfaceArea"
                    ],
                    "attached_condition": "(`world`.`country`.`Continent` = 'Europe')"
                  }
                }
              }
            }
          }
        },
        {
          "table": {
            "table_name": "ci",
            "access_type": "ref",
            "possible_keys": [
              "CountryCode"
            ],
            "key": "CountryCode",
            "used_key_parts": [
              "CountryCode"
            ],
            "key_length": "3",
            "ref": [
              "co.Code"
            ],
            "rows_examined_per_scan": 18,
            "rows_produced_per_join": 180,
            "filtered": "100.00",
            "cost_info": {
              "read_cost": "45.13",
              "eval_cost": "18.05",
              "prefix_cost": "66.81",
              "data_read_per_join": "12K"
            },
            "used_columns": [
              "ID",
              "Name",
              "CountryCode",
              "District",
              "Population"
            ]
          }
        }
      ]
    }
  }
}
1 row in set, 1 warning (0.0061 sec)
Listing 20-2

Example of the JSON EXPLAIN output

As you can see, the output is quite verbose, but the structure makes it relatively easy to see what information belongs together and how parts of the query relate to each other. In this example, there is a nested loop that includes two tables (co and ci). The co table itself includes a new query block that is a materialized subquery using the country table.

The JSON format also includes additional information such as the estimated cost of each part in the cost_info elements. The cost information can be used to see where the optimizer thinks the most expensive parts of the query are. If you, for example, see that the cost of a part of a query is very high, but your knowledge of the data means that you know that it should be cheap, it can suggest that the index statistics are not up to date or a histogram is needed.

The biggest issue of using the JSON-formatted output is that there is so much information and so many lines of output. A very convenient way to get around that is to use the Visual Explain feature in MySQL Workbench which is covered after discussing the tree-formatted output.

Tree Format

The tree format focuses on describing how the query is executed in terms of the relationship between the parts of the query and the order the parts are executed. In that sense, it may sound similar to the JSON output; however, the tree format is simpler to read, and there are not as many details. The tree format was introduced as an experimental feature in MySQL 8.0.16 and relies on the Volcano iterator executor. Starting with MySQL 8.0.18, the tree format is also used for the EXPLAIN ANALYZER feature .

Listing 20-3 shows the output using the tree format for the example query. This output is the non-analyze version. An example of the output of EXPLAIN ANALYZE will be shown shortly for the same query, so you can see the difference.
mysql> EXPLAIN FORMAT=TREE
       SELECT ci.ID, ci.Name, ci.District,
              co.Name AS Country, ci.Population
         FROM world.city ci
              INNER JOIN
                (SELECT Code, Name
                   FROM world.country
                  WHERE Continent = 'Europe'
                  ORDER BY SurfaceArea
                  LIMIT 10
                ) co ON co.Code = ci.CountryCode
        ORDER BY ci.Population DESC
        LIMIT 5G
*************************** 1. row ***************************
EXPLAIN:
-> Limit: 5 row(s)
    -> Sort: <temporary>.Population DESC, limit input to 5 row(s) per chunk
        -> Stream results
            -> Nested loop inner join
                -> Table scan on co
                    -> Materialize
                        -> Limit: 10 row(s)
                            -> Sort: country.SurfaceArea, limit input to 10 row(s) per chunk  (cost=25.40 rows=239)
                                -> Filter: (country.Continent = 'Europe')
                                    -> Table scan on country
                -> Index lookup on ci using CountryCode (CountryCode=co.`Code`)  (cost=4.69 rows=18)
Listing 20-3

Example of the tree EXPLAIN output

The output gives a good overview of how the query is executed. It can be easier to understand the execution by reading the output to some extent from the inside and out. For the nested loop, you have two tables, of which the first is a table scan on co (the indentation has been reduced):
-> Table scan on co
  -> Materialize
    -> Limit: 10 row(s)
      -> Sort: country.SurfaceArea, limit input to 10 row(s) per chunk  (cost=25.40 rows=239)
        -> Filter: (country.Continent = 'Europe')
           -> Table scan on country

Here you can see how the co table is a materialized subquery created by first doing a table scan on the country table, then applying a filter for the continent, then sorting based on the surface area, and then limiting the result to ten rows.

The second part of the nested loop is simpler as it just consists of an index lookup on the ci table (the city table) using the CountryCode index:
-> Index lookup on ci using CountryCode (CountryCode=co.`Code`)  (cost=4.69 rows=18)
When the nested loop has been resolved using an inner join, the result is streamed (i.e., not materialized) to the sorting, and the first five rows are returned:
-> Limit: 5 row(s)
    -> Sort: <temporary>.Population DESC, limit input to 5 row(s) per chunk
        -> Stream results
            -> Nested loop inner join
While this does not give quite as detailed a picture as the JSON output, it still includes a lot of information about the query plan. This includes the estimated cost and estimated number of rows for each of the tables. For example, from the sorting step on the countries’ surface area
(cost=25.40 rows=239)
A good question is how that relates to the actual cost of querying the table. You can use the EXPLAIN ANALYZE statement for this. Listing 20-4 shows an example of the output generated for the example query.
mysql> EXPLAIN ANALYZE
       SELECT ci.ID, ci.Name, ci.District,
              co.Name AS Country, ci.Population
         FROM world.city ci
              INNER JOIN
                (SELECT Code, Name
                   FROM world.country
                  WHERE Continent = 'Europe'
                  ORDER BY SurfaceArea
                  LIMIT 10
                ) co ON co.Code = ci.CountryCode
        ORDER BY ci.Population DESC
        LIMIT 5G
*************************** 1. row ***************************
EXPLAIN: -> Limit: 5 row(s)  (actual time=34.492..34.494 rows=5 loops=1)
    -> Sort: <temporary>.Population DESC, limit input to 5 row(s) per chunk  (actual time=34.491..34.492 rows=5 loops=1)
        -> Stream results  (actual time=34.371..34.471 rows=15 loops=1)
            -> Nested loop inner join  (actual time=34.370..34.466 rows=15 loops=1)
                -> Table scan on co  (actual time=0.001..0.003 rows=10 loops=1)
                    -> Materialize  (actual time=34.327..34.330 rows=10 loops=1)
                        -> Limit: 10 row(s)  (actual time=34.297..34.301 rows=10 loops=1)
                            -> Sort: country.SurfaceArea, limit input to 10 row(s) per chunk  (cost=25.40 rows=239) (actual time=34.297..34.298 rows=10 loops=1)
                                -> Filter: (world.country.Continent = 'Europe')  (actual time=0.063..0.201 rows=46 loops=1)
                                    -> Table scan on country  (actual time=0.057..0.166 rows=239 loops=1)
                -> Index lookup on ci using CountryCode (CountryCode=co.`Code`)  (cost=4.69 rows=18) (actual time=0.012..0.013 rows=2 loops=10)
1 row in set (0.0353 sec)
Listing 20-4

Example of the EXPLAIN ANALYZE output

This is the same tree output as for FORMAT=TREE except that for each step, there is information about the performance. If you look at the line for the ci table, you can see there are two timings, the number of rows and the number of loops (reformatted to improve the readability):
-> Index lookup on ci using CountryCode
     (CountryCode=co.`Code`)
     (cost=4.69 rows=18)
     (actual time=0.012..0.013 rows=2 loops=10)

Here the estimated cost was 4.69 for an expected 18 rows (per loop). The actual statistics show that the first row was read after 0.012 millisecond and all rows were read after 0.013 millisecond. There were ten loops (one for each of the ten countries), each fetching an average of two rows for a total of 20 rows. So, in this case, the estimate was not very accurate (because the query exclusively picks small countries).

Note

The row count for EXPLAIN ANALYZE is the average per loop rounded to an integer. With rows=2 and loops=10, this means the total number of rows read is between 15 and 24. In this specific example, using the table_io_waits_summary_by_table table in the Performance Schema shows that 15 rows are read.

If you have queries that use the hash joins in MySQL 8.0.18 and later, you will need to use the tree-formatted output to confirm when the hash join algorithm is used. For example, if the city table is joined with the country table using a hash join
mysql> EXPLAIN FORMAT=TREE
       SELECT CountryCode, country.Name AS Country,
              city.Name AS City, city.District
         FROM world.country IGNORE INDEX (Primary)
              INNER JOIN world.city IGNORE INDEX (CountryCode)
                      ON city.CountryCode = country.CodeG
*************************** 1. row ***************************
EXPLAIN:
-> Inner hash join (world.city.CountryCode = world.country.`Code`)  (cost=100125.16 rows=4314)
    -> Table scan on city  (cost=0.04 rows=4188)
    -> Hash
        -> Table scan on country  (cost=25.40 rows=239)
1 row in set (0.0005 sec)

Notice how the join is an Inner hash join and that the table scan on the country table is given as using a hash.

Thus far, all the examples have used text-based outputs. Particularly the JSON-formatted output could be difficult to use to get an overview of the query plan. For that Visual Explain is a better option.

Visual Explain

The Visual Explain feature is part of MySQL Workbench and works by converting the JSON-formatted query plan into a graphical representation. You have already used Visual Explain back in Chapter 16 when you investigated the effect of adding a histogram to the sakila.film table.

You get the Visual Explain diagram by clicking the icon with the magnifying glass in front of the lightning symbol as shown in Figure 20-1.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig1_HTML.jpg
Figure 20-1

Obtaining the Visual Explain diagram for a query

This is a particularly useful way to generate the query plan, if the query takes a long time to execute or the query modifies the data. If you already have executed the query, you can alternatively click the Execution Plan icon to the right of the result grid as it is shown in Figure 20-2.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig2_HTML.jpg
Figure 20-2

Retrieving the execution plan from the result grid window

The Visual Explain diagram is created as a flowchart with one rectangle per query block and table. The processing of the data is depicted using other shapes such as a diamond for a join. Figure 20-3 shows an example for each of the basic shapes used in Visual Explain.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig3_HTML.jpg
Figure 20-3

Examples of the shapes used in Visual Explain

In the figure, a query block is gray, while the two examples of a table (the single row lookup and full table scan in the subquery) are blue and red, respectively. The gray blocks are also used, for example, in case of unions. The text below a table box shows the table name or alias in standard text and the index name in bold text. The rectangles with rounded corners depict operations on the rows such as sorting, grouping, distinct operations, and so on.

The number to the top left is the relative cost for that table, operation, or query block. The number to the top right of tables and joins is the number of rows estimated to be carried forward. The color of the operations is used to show how expensive it is to apply the operation. Tables also use colors based on the table access type, primarily to group similar access types and secondarily to indicate the cost of the access type. The relationship between the color and cost using the cost estimated from Visual Explain can be seen in Figure 20-4.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig4_HTML.png
Figure 20-4

Color codes for the relative cost of operations and table access

Blue (1) is the cheapest; green (2), yellow (3), and orange (4) represent low to medium costs; and the most expensive access types and operations are red symbolizing a high (5) to very high (6) cost.

There is a good deal of overlap between the color groups. Each cost estimate is considering an “average” use case, so the cost estimates should not be taken as an absolute truth. Query optimization is complex, and sometimes a method that is usually cheaper than another method for one particular query turns out to give better performance.

Note

The author of this book once decided to improve a query that had a query plan which looked terrible: internal temporary tables, file sorting, poor access methods, and so on. After a long time rewriting the query and verifying whether the tables had the correct indexes, the query plan looked beautiful – but it turned out the query performed worse than the original. The lesson: Always test the query performance after optimization and do not rely on whether the cost of the access methods and operations has improved on paper.

For the tables, the cost is associated with the access type, which is the value of the type column in the traditional EXPLAIN output and access_type field in the JSON-formatted output. Figure 20-5 shows how Visual Explain represents the 12 access types that currently exist. The explanation of the access types is deferred until the next section.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig5_HTML.jpg
Figure 20-5

The access types as displayed in Visual Explain

Additionally, Visual Explain has an “unknown” access type colored black in case it comes across an access type that is not known. The access types are ordered from left to right and then top to bottom according to their color and approximate cost.

Figure 20-6 puts all of this together to display the query plan for the example query that has been used throughout this section.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig6_HTML.jpg
Figure 20-6

The Visual Explain diagram for the example query

You read the diagram from the bottom left to the right and then up. So the diagram shows that the subquery with a full table scan on the country table is performed first and then another full table scan on the materialized co table with the rows joined on the ci (city) table using a nonunique index lookup. Finally, the result is sorted using a temporary table and a file sort.

If you want more details than the diagram shows initially, you can hover over the part of the query plan you want to know more about. Figure 20-7 shows an example of the details included for the ci table .
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig7_HTML.jpg
Figure 20-7

Details for the ci table in Visual Explain

Not only does the pop-up frame show the remaining details that also are available in the JSON output, there are also hints to help understand what the data means. All of this means that Visual Explain is a great way to get started analyzing queries through their query plans. As you gain experience, you may prefer using the text-based outputs, particularly if you prefer to work from a shell, but do not dismiss Visual Explain because you think it is better to use the text-based output format. Even for experts, Visual Explain is a great tool for understanding how queries are executed.

Hopefully, discussing the output formats has given you an idea of what information EXPLAIN can give you. Yet, to fully understand it and take advantage of it, it is necessary to dive deeper into the meaning of the information.

EXPLAIN Output

There is a lot of information available in the explain outputs, so it is worth delving into what this information means. This section starts out with an overview of the fields included in the traditional and JSON-formatted outputs; then the select types and access types and the extra information will be covered in more detail.

EXPLAIN Fields

The first step to use the EXPLAIN statement constructively in your work to improve your queries is to understand what information is available. The information ranges from an id to make a reference to the query parts to details about the indexes that can be used for the query compared to what is used and what optimizer features are applied.

Do not worry if you cannot recall all the details after reading the definitions the first time. Most of the fields are quite self-explanatory, so you can make a qualified guess at the data they represent. As you analyze some queries yourself, you will also quickly become familiar with the information. Table 20-1 lists all the fields included in the traditional format as well as some common fields from the JSON format.
Table 20-1

The EXPLAIN fields

Traditional

JSON

Description

id

select_id

A numeric identifier that shows which part of the query the table or subquery is part of. The top-level tables have id = 1, the first subquery has id = 2, and so forth. In case of a union, the id will be NULL with the table value set to <unionM,N> (see also the table column) for the row that represents the aggregation of the union result.

select_type

 

This shows how the table will be included in the overall statement. The known select types will be discussed later in the “Select Types” section. For the JSON format, the select type is implied by the structure of the JSON document and from fields such as dependent and cacheable.

 

dependent

Whether it is a dependent subquery, that is, it depends on the outer parts of the query.

 

cacheable

Whether the result of the subquery can be cached or it must be reevaluated for each row in the outer query.

table

table_name

The name of the table or subquery. If an alias has been specified, it is the alias that is used. This ensures that each table name is unique for a given value of the id column. Special cases include unions, derived tables, and materialized subqueries where the table name is <unionM,N>, <derivedN>, and <subqueryN>, respectively, where N and M refer to the ids of earlier parts of the query plan.

partitions

partitions

The partitions that will be included for the query. You can use this to determine whether partition pruning is applied as expected.

type

access_type

How the data is accessed. This shows how the optimizer has decided to limit the number of rows that are examined in the table. The types will be discussed in the “Access Types” section.

possible_keys

possible_keys

A list of the indexes that are candidates to be used for the table. A key name using the schema <auto_key0> means an auto-generated index is available.

key

key

The index(es) chosen for the table. A key name using the schema <auto_key0> means an auto-generated index is used.

key_len

key_length

The number of bytes that are used of the index. For indexes that consist of multiple columns, the optimizer may only be able to use a subset of the columns. In that case, the key length can be used to determine how much of the index is useful for this query. If the column in the index supports NULL values, 1 byte is added to the length compared to the case of a NOT NULL column .

 

used_key_parts

The columns in the index that are used.

ref

ref

What the filtering is performed against. This can, for example, be a constant for a condition like <table>.<column> = 'abc' or a name of a column in another table in case of a join.

rows

rows_examined_per_scan

An estimate of the number of rows that is the result of including the table. For a table that is joined to an earlier table, it is the number of rows estimated to be found per join. A special case is when the reference is the primary key or a unique key on the table, in which case the row estimate is exactly 1.

 

rows_produced_per_join

The estimated number of rows resulting from the join. Effectively the number of loops expected multiplied with rows_examined_per_scan and the percentage of rows filtered.

filtered

filtered

This is an estimate of how many of the examined rows will be included. The value is in percent, so that for a value of 100.00 all examined rows will be returned. A value of 100.00 is the optimal, and the worst value is 0.

Note: The rounding of the value in the traditional format depends on the client you use. MySQL Shell will, for example, return 100 where the mysql command-line client returns 100.00.

 

cost_info

A JSON object with the breakdown of the cost of the query part.

Extra

 

Additional information about the decisions of the optimizer. This can include information about the sorting algorithm used, whether a covering index is used, and so on. The most common of the supported values will be discussed in the section “Extra Information.”

 

message

Information that is in the Extra column for the traditional output that does not have a dedicated field in the JSON output. An example is Impossible WHERE .

 

using_filesort

Whether a file sort is used.

 

using_index

Whether a covering index is used.

 

using_temporary_table

Whether an operation such as a subquery or sorting requires an internal temporary table.

 

attached_condition

The WHERE clause associated with the part of the query.

 

used_columns

The columns required from the table. This is useful to see if you are close to be able to use a covering index.

Some of the information appears at first to be missing in the JSON format as the field only exists for the traditional format. That is not the case; instead the information is available using other means, for example, several of the messages in Extra have their own field in the JSON format. Other Extra messages use the message field. Some of the fields that are not included in the table for the JSON output will be mentioned when discussing the information in the Extra column later in this section.

In general, Boolean fields in the JSON-formatted output are omitted, if the value is false; one exception is for cacheable as a non-cacheable subquery or union indicates a higher cost compared to the cacheable cases.

For the JSON output, there are also fields used to group information for an operation. The operations range from accessing a table to complex operations that group several operations. Some of the common operations with examples of what triggers them are
  • table: Access a table. This is the lowest level of the operations.

  • query_block: The highest-level concept with one query block corresponding to an id for the traditional format. All queries have at least one query block.

  • nested_loop: A join operation.

  • grouping_operation: The operation, for example, resulting from a GROUP BY clause.

  • ordering_operation: The operation, for example, resulting for an ORDER BY clause.

  • duplicates_removal: The operation, for example, resulting when using the DISTINCT keyword.

  • windowing: The operation resulting from using window functions.

  • materialized_from_subquery: Execute a subquery and materialize the result.

  • attached_subqueries: A subquery that is attached to the rest of the query. This, for example, happens with clauses such as IN (SELECT ...) for the subquery inside the IN clause.

  • union_result: For queries using UNION to combine the result of two or more queries. Inside the union_result block, there is a query_specifications block with the definition of each query in the union.

The fields in Table 20-1 and the list of complex operations are not comprehensive for the JSON format, but it should give you a good idea of the information available. In general, the field names carry information in themselves, and combining with the context where they occur is usually enough to understand the meaning of the field. The values of some of the fields deserve some more attention though – starting with the select types.

Select Types

The select type shows what kind of query block each part of the query is. A part of a query can in this context include several tables. For example, if you have a simple query joining a list of tables but not using constructs such as subqueries, then all tables will be in the same (and only) part of the query. Each part of the query gets each own id (select_id in the JSON output).

There are several select types. For most of them, there is no direct field in the JSON output; however, it is possible to derive the select type from the structure and some of the other fields. Table 20-2 shows the currently existing select types with hints how to derive the type from the JSON output. In the table, the value of the Select Type column is the value used for the select_type column in the traditional output format.
Table 20-2

EXPLAIN select types

Select Type

JSON

Description

SIMPLE

 

For SELECT queries not using derived tables, subqueries, unions, or similar.

PRIMARY

 

For queries using subqueries or unions, the primary part is the outermost part.

INSERT

 

For INSERT statements.

DELETE

 

For DELETE statements.

UPDATE

 

For UPDATE statements.

REPLACE

 

For REPLACE statements.

UNION

 

For union statements, the second or later SELECT statement.

DEPENDENT UNION

dependent=true

For union statements, the second or later SELECT statement where it depends on an outer query.

UNION RESULT

union_result

The part of the query that aggregates the results from the union SELECT statements.

SUBQUERY

 

For SELECT statements in subqueries.

DEPENDENT SUBQUERY

dependent=true

For dependent subqueries, the first SELECT statement.

DERIVED

 

A derived table – a table created through a query but otherwise behaves like a normal table.

DEPENDENT DERIVED

dependent=true

A derived table dependent on another table.

MATERIALIZED

materialized_from_subquery

A materialized subquery.

UNCACHEABLE SUBQUERY

cacheable=false

A subquery where the result must be evaluated for each row in the outer query.

UNCACHEABLE UNION

cacheable=false

For a union statement, a second or later SELECT statement that is part of an uncacheable subquery.

Some of the select types can be taken just as information to make it easier to understand which part of the query you are looking at. This, for example, includes PRIMARY and UNION. However, some of the select types indicate that it is an expensive part of the query. This particularly applies to the uncacheable types. Dependent types also mean that the optimizer has less flexibility when deciding where in the execution plan to add the table. If you have slow queries and you see uncacheable or dependent parts, it can be worth looking into whether you can rewrite those parts or split the query into two.

Another important piece of information is how the tables are accessed.

Access Types

The table access types were already encountered when Visual Explain was discussed. They show whether a query accesses the table using an index, scan, and similar. Since the cost associated with each access type varies greatly, it is also one of the important values to look for in the EXPLAIN output to determine which parts of the query to work on to improve the performance.

The rest of this subsection summarizes the access types in MySQL. The headings are the values used in the type column in the traditional format. For each access type, there is an example that uses that access type.

system

The system access type is used with tables that have exactly one row. This means the table can be treated as a constant. The Visual Explain cost, message, and color are as follows:
  • Cost: Very low

  • Message: Single Row (system constant)

  • Color: Blue

An example of a query using the system access type is
SELECT *
  FROM (SELECT 1) my_table

The system access type is a special case of the const access type.

const

At most one row is matched for the table, for example, when there is a filter on a single value of the primary key or a unique index. The Visual Explain cost, message, and color are as follows:
  • Cost: Very low

  • Message: Single row (constant)

  • Color: Blue

An example of a query using the const access type is
SELECT *
  FROM world.city
 WHERE ID = 130;

eq_ref

The table is the right-hand table in a join where the condition on the table is on a primary key or not null unique index. The Visual Explain cost, message, and color are as follows:
  • Cost: Low

  • Message: Unique key lookup

  • Color: Green

An example of a query using the eq_ref access type is
SELECT *
  FROM world.city
       STRAIGHT_JOIN world.country
             ON CountryCode = Code;

The eq_ref access type is a specialized case of the ref access type where only one row can be returned per lookup.

ref

The table is filtered by a nonunique secondary index. The Visual Explain cost, message, and color are as follows:
  • Cost: Low to medium

  • Message: Non-unique key lookup

  • Color: Green

An example of a query using the ref access type is
SELECT *
  FROM world.city
 WHERE CountryCode = 'AUS';

ref_or_null

The same as ref but the filtered column may also be NULL. The Visual Explain cost, message, and color are as follows:
  • Cost: Low to medium

  • Message: Key lookup + fetch NULL values

  • Color: Green

An example of a query using the ref_or_null access type is
SELECT *
  FROM sakila.payment
 WHERE rental_id = 1
       OR rental_id IS NULL;

index_merge

The optimizer chooses a combination of two or more indexes to resolve a filter that includes an OR or AND between columns in different indexes. The Visual Explain cost, message, and color are as follows:
  • Cost: Medium

  • Message: Index merge

  • Color: Green

An example of a query using the index_merge access type is
SELECT *
  FROM sakila.payment
 WHERE rental_id = 1
       OR customer_id = 5;

While the cost is listed as medium, one of the more common severe performance issues is a query usually using a single index or doing a full table scan and the index statistics becoming inaccurate, so the optimizer chooses an index merge. If you have a poorly performing query using an index merge, try to tell the optimizer to ignore the index merge optimization or the used indexes and see if that helps or analyze the table to update the index statistics. Alternatively, the query can be rewritten to a union of two queries, with each query using a part of the filter. An example of this will be shown in Chapter 24.

fulltext

The optimizer chooses a full text index to filter the table. The Visual Explain cost, message, and color are as follows:
  • Cost: Low

  • Message: Fulltext index search

  • Color: Yellow

An example of a query using the fulltext access type is:
SELECT *
  FROM sakila.film_text
 WHERE MATCH(title, description)
       AGAINST ('Circus' IN BOOLEAN MODE);

unique_subquery

For a subquery inside an IN operator where the subquery returns the value of a primary key or unique index. In MySQL 8 these queries are usually rewritten by the optimizer, so unique_subquery requires disabling the materialization and semijoin optimizer switches. The Visual Explain cost, message, and color are as follows:
  • Cost: Low

  • Message: Unique key lookup into table of subquery

  • Color: Orange

An example of a query using the unique_subquery access type is
SET optimizer_switch = 'materialization=off,semijoin=off';
SELECT *
  FROM world.city
 WHERE CountryCode IN (
         SELECT Code
           FROM world.country
          WHERE Continent = 'Oceania');
SET optimizer_switch = 'materialization=on,semijoin=on';

The unique_subquery access method is a special case of the index_subquery method for the case where a primary or unique index is used.

index_subquery

For a subquery inside an IN operator where the subquery returns the value of a secondary nonunique index. In MySQL 8 these queries are usually rewritten by the optimizer, so unique_subquery requires disabling the materialization and semijoin optimizer switches. The Visual Explain cost, message, and color are as follows:
  • Cost: Low

  • Message: Nonunique key lookup into table of subquery

  • Color: Orange

An example of a query using the index_subquery access type is
SET optimizer_switch = 'materialization=off,semijoin=off';
SELECT *
  FROM world.country
 WHERE Code IN (
         SELECT CountryCode
           FROM world.city
          WHERE Name = 'Sydney');
SET optimizer_switch = 'materialization=on,semijoin=on';

range

The range access type is used when an index is used to look up several values either in sequence or in groups. It is used both for explicit ranges like ID BETWEEN 1 AND 10, for IN clauses, or where several conditions on the same column are separated by OR. The Visual Explain cost, message, and color are as follows:
  • Cost: Medium

  • Message: Index range scan

  • Color: Orange

An example of a query using the range access type is
SELECT *
  FROM world.city
 WHERE ID IN (130, 3805);

The cost of using range access largely depends on how many rows are included in the range. In one extreme, the range scan only matches a single row using the primary key, so the cost is very low. In the other extreme, the range scan includes a large part of the table using a secondary index in which case it can end up being cheaper to perform a full table scan.

The range access type is related to the index access type with the difference being whether partial or a full scan is required.

index

The optimizer has chosen to perform a full index scan. This may be chosen in combination of using a covering index. The Visual Explain cost, message, and color are as follows:
  • Cost: High

  • Message: Full index scan

  • Color: Red

An example of a query using the index access type is
SELECT ID, CountryCode
  FROM world.city;

Since an index scan requires a second lookup using the primary key, it can become very expensive unless the index is a covering index for the query, to the extent that it ends up being cheaper to perform a full table scan.

ALL

The most basic access type is to scan all rows for the table. It is also the most expensive access type, and for this reason the type is written in all uppercase. The Visual Explain cost, message, and color are as follows:
  • Cost: Very high

  • Message: Full table scan

  • Color: Red

An example of a query using the ALL access type is
SELECT *
  FROM world.city;

If you see a table other than the first table using a full table scan, it is usually a red flag that indicates that either there is a missing condition on the table or there are no indexes that can be used. Whether ALL is a reasonable access type for the first table depends on how much of the table you need for the query; the larger the part of the table is required, the more reasonable a full table scan is.

Note

While a full table scan is considered the most expensive access type, it is together with primary key lookups the cheapest per row. So, if you genuinely need to access most or all of the table, a full table scan is the most effective way to read the rows.

That concludes the discussion of the access types for now. The access types will be referenced again when looking at EXPLAIN examples later in this chapter as well as later in the book when looking at optimizing queries, for example, in Chapter 24. In the meantime, let’s look at the information in the Extra column.

Extra Information

The Extra column in the traditional output format is a catch-all bin for information that does not have its own column. When the JSON format was introduced, there was no reason to keep it as it was easy to introduce additional fields and it is not necessary to include all fields for every output. For that reason, the JSON format does not have an Extra field but instead has a range of fields. A few leftover messages have been left for a generic message field.

Note

The information available in the Extra column is in some cases storage engine dependent or only used in rare cases. This discussion will only cover the most commonly encountered messages. For a full list of messages, refer to the MySQL reference manual at https://dev.mysql.com/doc/refman/en/explain-output.html#explain-extra-information.

Some of the more commonly occurring messages include
  • Using index: When a covering index is used. For the JSON format, the using_index field is set to true.

  • Using index condition: When an index is used to test whether it is necessary to read the full row. This is, for example, used when there is a range condition on an indexed column. For the JSON format, the index_condition field is set with the filter condition.

  • Using where: When a WHERE clause is applied to the table without using an index. This may be an indication that the indexes on the table are not optimal. In the JSON format, the attached_condition field is set with the filter condition.

  • Using index for group-by: When a loose index scan is used to resolve GROUP BY or DISTINCT. In the JSON format, the using_index_for_group_by field is set to true.

  • Using join buffer (Block Nested Loop): This means that a join is made where no index can be used, so the join buffer is used instead. Tables with this message are candidates to have an index added. For the JSON format, the using_join_buffer field is set to Block Nested Loop. One thing to be aware of is that when a hash join is used, then the traditional and JSON-formatted outputs will still show that a block nested loop is used. To see whether it is an actual block nested loop join or a hash join, you need to use the tree-formatted output.

  • Using join buffer (Batched Key Access): This means that a join is using the Batched Key Access (BKA) optimization. To enable the Batched Key Access optimization, you must enable the mrr (defaults to on) and batch_key_access (defaults to off) and disable the mrr_cost_based (defaults to on) optimizer switches. The optimization requires an index for the join, so unlike using the join buffer for a block nested loop, using the Batched Key Access algorithm is not a sign of expensive access to the table. For the JSON format, the using_join_buffer field is set to Batched Key Access.

  • Using MRR: The Multi-Range Read (MRR) optimization is used. This is sometimes used to reduce the amount of random I/O for range conditions on secondary indexes where the full row is needed. The optimization is controlled by the mrr and mrr_cost_based optimizer switches (both are enabled by default). For the JSON format, the using_MRR field is set to true.

  • Using filesort: MySQL uses an extra pass to determine how to retrieve the rows in the correct order. This, for example, happens with sorting by a secondary index; and the index is not a covering index. For the JSON format, the using_filesort field is set to true.

  • Using temporary: An internal temporary table is used to store the result of a subquery, for sorting, or for grouping. For sorting and grouping, the use of an internal temporary table can sometimes be avoided by adding an index or rewriting the query. For the JSON format, the using_temporary_table field is set to true.

  • sort_union(...), Using union(...), Using intersect(...): These three messages are used with index merges to say how the index merge is performed. For either message, information about the indexes involved in the index merge is included inside the parentheses. For the JSON format, the key field specifies the method and indexes used.

  • Recursive: The table is part of a recursive common table expression (CTE). For the JSON format, the recursive field is set to true.

  • Range checked for each record (index map: 0x1): This happens when you have a join where there is a condition on an indexed column of the second table that depends on the value of a column from the first table, for example, with an index on t2.val2: SELECT * FROM t1 INNER JOIN t2 WHERE t2.val2 < t1.val1; This is what triggers the NO_GOOD_INDEX_USED counter in the Performance Schema statement event tables to increment. The index map is a bitmask that indicates which indexes are candidates for the range check. The index numbers are 1-based as shown by SHOW INDEXES. When you write out the bitmask, the index numbers with the bit set are the candidates. For the JSON format, the range_checked_for_each_record field is set to the index map.

  • Impossible WHERE: When there is a filter that cannot possibly be true, for example, WHERE 1 = 0. This also applies if the value in the filter is outside the range supported by the data type, for example, WHERE ID = 300 for a tinyint data type. For the JSON format, the message is added to the message field.

  • Impossible WHERE noticed after reading const tables: The same as Impossible WHERE except it applies after resolving the tables using the system or const access method. An example is SELECT * FROM (SELECT 1 AS ID) a INNER JOIN city USING (ID) WHERE a.id = 130; For the JSON format, the message is added to the message field.

  • Impossible HAVING: The same as Impossible WHERE except it applies to a HAVING clause. For the JSON format, the message is added to the message field.

  • Using index for skip scan: When the optimizer chooses to use multiple range scans similar to a loose index scan. It can, for example, be used for a covering index where the first column of the index is not used for the filter condition. This method is available in MySQL 8.0.13 and later. For the JSON format, the using_index_for_skip_scan field is set to true.

  • Select tables optimized away: This message means that MySQL was able to remove the table from the query because only a single row will result, and that row can be generated from a deterministic set of rows. It usually occurs when only the minimum and/or maximum values of an index are required from the table. For the JSON format, the message is added to the message field.

  • No tables used: For subqueries that do not involve any tables, for example, SELECT 1 FROM dual; For the JSON format, the message is added to the message field.

  • no matching row in const table: For a table where the system or const access type is possible but there are no rows matching the condition. For the JSON format, the message is added to the message field.

Tip

At the time of writing, you need to use the tree-formatted output to see if a join that does not use indexes is using the hash join algorithm.

That concludes the discussion about the meaning of the output of the EXPLAIN statement. All there is left is to start using it to examine the query plans.

EXPLAIN Examples

To finish off the discussion of query plans, it is worth going through a few examples to get a better feeling of how you can put all of it together. The examples here are meant as an introduction. Further examples will occur in the remainder of the book, particularly Chapter 24.

Single Table, Table Scan

As the first example, consider a query on the city table in the world sample database with a condition on the non-indexed column Name. Since there is no index that can be used, it will require a full table scan to evaluate the query. An example of a query matching these requirements is
SELECT *
  FROM world.city
 WHERE Name = 'London';
Listing 20-5 shows the traditional EXPLAIN output for the query.
mysql> EXPLAIN
        SELECT *
          FROM world.city
         WHERE Name = 'London'G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: city
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 4188
     filtered: 10
        Extra: Using where
1 row in set, 1 warning (0.0007 sec)
Listing 20-5

The EXPLAIN output for a single table with a table scan

The output has the access type set to ALL which is also what would be expected since there are no conditions on columns with indexes. It is estimated that 4188 rows will be examined (the actual number is 4079) and for each row a condition from the WHERE clause will be applied. It is expected that 10% of the rows examined will match the WHERE clause (note that depending on the client used, the output for the filtered column may say 10 or 10.00). Recall from the optimizer discussion in Chapter 17 that the optimizer uses default values to estimate the filtering effect of various conditions, so you cannot use the filtering value directly to estimate whether an index is useful.

The corresponding Visual Explain diagram can be seen in Figure 20-8.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig8_HTML.jpg
Figure 20-8

Visual Explain diagram for a single table with a table scan

The full table scan is shown by a red Full Table Scan box, and it can be seen that the cost is estimated to be 425.05.

This query just returns two rows (the table has a London in England and one in Ontario, Canada). What happens if all cities in a single country are requested instead?

Single Table, Index Access

The second example is similar to the first except the filter condition is changed to use the CountryCode column which has a secondary nonunique index. This should make it cheaper to access matching rows. For this example, all German cities will be retrieved:
SELECT *
  FROM world.city
 WHERE CountryCode = 'DEU';
Listing 20-6 shows the traditional EXPLAIN output for the query.
mysql> EXPLAIN
        SELECT *
          FROM world.city
         WHERE CountryCode = 'DEU'G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: city
   partitions: NULL
         type: ref
possible_keys: CountryCode
          key: CountryCode
      key_len: 3
          ref: const
         rows: 93
     filtered: 100
        Extra: NULL
1 row in set, 1 warning (0.0008 sec)
Listing 20-6

The EXPLAIN output for a single table with index lookups

This time the possible_keys column shows that the CountryCode index can be used for the query, and the key column shows that the index is used. The access type is ref to reflect that a nonunique index is used for the table access. It is estimated that 93 rows will be accessed, which is exact as the optimizer asks InnoDB how many rows will match. The filtered column shows that the index does a perfect job of filtering the table. The corresponding Visual Explain diagram is shown in Figure 20-9.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig9_HTML.jpg
Figure 20-9

Visual Explain diagram for a single table with index lookup

Despite returning more than 45 times as many rows as the first example, the cost is only estimated as 28.05 or less than one-tenth of the cost of a full table scan.

What happens if only the ID and CountryCode columns are used?

Two Tables and a Covering Index

If there is an index that includes all columns required from the table, then it is called a covering index. MySQL will use this to avoid retrieving the whole row. Since the CountryCode index of the city table is a nonunique index, it also includes the ID column as it is the primary key. To make the query a little more realistic, the query will also include the country table and filter the countries included based on the continent. An example of such a query is
SELECT ci.ID
  FROM world.country co
       INNER JOIN world.city ci
          ON ci.CountryCode = co.Code
 WHERE co.Continent = 'Asia';
Listing 20-7 shows the traditional EXPLAIN output for the query.
mysql> EXPLAIN
        SELECT ci.ID
          FROM world.country co
               INNER JOIN world.city ci
                  ON ci.CountryCode = co.Code
         WHERE co.Continent = 'Asia'G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: co
   partitions: NULL
         type: ALL
possible_keys: PRIMARY
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 239
     filtered: 14.285715103149414
        Extra: Using where
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: ci
   partitions: NULL
         type: ref
possible_keys: CountryCode
          key: CountryCode
      key_len: 3
          ref: world.co.Code
         rows: 18
     filtered: 100
        Extra: Using index
Listing 20-7

The EXPLAIN output for a simple join between two tables

The query plan shows that the optimizer has chosen to start with a full table scan on the co (country) table and to use the CountryCode index for the join on the ci (city) table. What is special here is that the Extra column includes Using index. So it is not necessary to read the full row of the city table. Notice also that the key length is 3 (bytes) which is the width of the CountryCode column. The corresponding Visual Explain diagram can be seen in Figure 20-10.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig10_HTML.jpg
Figure 20-10

Visual Explain diagram for a simple join between two tables

The key_len field does not include the primary key part of the index even though it is used. It is however useful to see how much of a multicolumn index is used.

Multicolumn Index

The countrylanguage table has a primary key that includes the CountryCode and Language columns. Imagine you want to find all languages spoken in a single country; in that case you need to filter on CountryCode but not on Language. The index can still be used to perform the filtering, and you can use the key_len field of the EXPLAIN output to see how much of the index is used. A query that can be used to find all languages spoken in China is
SELECT *
  FROM world.countrylanguage
 WHERE CountryCode = 'CHN';
Listing 20-8 shows the traditional EXPLAIN output for the query.
mysql> EXPLAIN
        SELECT *
          FROM world.countrylanguage
         WHERE CountryCode = 'CHN'G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: countrylanguage
   partitions: NULL
         type: ref
possible_keys: PRIMARY,CountryCode
          key: PRIMARY
      key_len: 3
          ref: const
         rows: 12
     filtered: 100
        Extra: NULL
Listing 20-8

The EXPLAIN output using part of a multicolumn index

The total width of the primary key is 3 bytes from the CountryLanguage column and 30 bytes from the Language column. Since the key_len column shows that only 3 bytes is used, it can be concluded only the CountryLanguage part of the index is used for filtering (the used part of the index is always the leftmost part). In Visual Explain you need to hover over the table in question to get the extended information as shown in Figure 20-11.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig11_HTML.jpg
Figure 20-11

Visual Explain diagram for using part of a multicolumn index

In the figure, look for the Used Key Parts label under Key/Index: PRIMARY. This directly shows that only the CountryCode column of the index is used.

As a final example, let’s return to the query that was used as an example when going through the EXPLAIN formats.

Two Tables with Subquery and Sorting

The example query that has been used extensively earlier in the chapter will be used to round off the discussion about EXPLAIN. The query uses a mix of various features, so it triggers several parts of the information that has been discussed. It is also an example of a query with multiple query blocks. As a reminder, the query is repeated here.

The output of the traditional EXPLAIN format is repeated in Listing 20-9.
mysql> EXPLAIN
       SELECT ci.ID, ci.Name, ci.District,
              co.Name AS Country, ci.Population
         FROM world.city ci
              INNER JOIN
                (SELECT Code, Name
                   FROM world.country
                  WHERE Continent = 'Europe'
                  ORDER BY SurfaceArea
                  LIMIT 10
                ) co ON co.Code = ci.CountryCode
        ORDER BY ci.Population DESC
        LIMIT 5G
*************************** 1. row ***************************
           id: 1
  select_type: PRIMARY
        table: <derived2>
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 10
     filtered: 100
        Extra: Using temporary; Using filesort
*************************** 2. row ***************************
           id: 1
  select_type: PRIMARY
        table: ci
   partitions: NULL
         type: ref
possible_keys: CountryCode
          key: CountryCode
      key_len: 3
          ref: co.Code
         rows: 18
     filtered: 100
        Extra: NULL
*************************** 3. row ***************************
           id: 2
  select_type: DERIVED
        table: country
   partitions: NULL
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 239
     filtered: 14.285715103149414
        Extra: Using where; Using filesort
Listing 20-9

The EXPLAIN output when joining a subquery and a table

The Visual Explain diagram for the query is repeated in Figure 20-12. Before proceeding to read the analysis of the output, you are encouraged to study it on your own.
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig12_HTML.jpg
Figure 20-12

Visual Explain diagram for joining a subquery and a table

The query plan starts out with the subquery that uses the country table to find the ten smallest countries by area. The subquery is given the table label <derived2>, so you will need to find the row (could be several rows for other queries) with id = 2 which is row 3 in this case. Row 3 has the select type set to DERIVED, so it is a derived table; that is a table created through a query but otherwise behaves like a normal table. The derived table is generated using a full table scan (type = ALL) with a WHERE clause applied to each row, followed by a file sort. The resulting derived table is materialized (visible from Visual Explain) and called co.

Once the derived table has been constructed, it is used as the first table for the join with the ci (city) table. You can see that from the ordering of the rows with <derived2> in row 1 and ci in row 2. For each row in the derived table, it is estimated that 18 rows will be examined in the ci table using the CountryCode index. The CountryCode index is a nonunique index which can be seen from the label for the table box in Visual Explain, and the type column has the value ref. It is estimated that the join will return 180 rows which comes from the ten rows in the derived table multiplied with the estimate of 18 rows per index lookup in the ci table.

Finally, the result is sorted using an internal temporary table and a file sort. The total cost of the query is estimated to be 247.32.

Thus far, the discussion has been on what the query plan ended up being. If you want to know how the optimizer got there, you will need to examine the optimizer trace.

Optimizer Trace

The optimizer trace is not needed very often, but sometimes when you encounter an unexpected query plan, it can be useful to see how the optimizer got there. That is what the optimizer trace shows.

Tip

Most often when a query plan is not what you expect, it is because of a missing or wrong WHERE clause, a missing or wrong join condition, or some other kind of error in the query or because the index statistics are not correct. Check these things before diving into the gory details of the optimizer’s decision process.

The optimizer trace is enabled by setting the optimizer_trace option to 1. This makes the optimizer record the trace information for the subsequent queries (until optimizer_trace is disabled again), and the information is made available through the information_schema.OPTIMIZER_TRACE table. The maximum number of traces that are retained is configured with the optimizer_trace_limit option (defaults to 1).

You can choose between executing the query you need the optimizer trace for and using EXPLAIN to get the query plan. The latter is very useful as it gives you both the query plan and the optimizer trace. A typical workflow to get the optimizer trace for a query is as follows:
  1. 1.

    Enable the optimizer_trace option for the session.

     
  2. 2.

    Execute EXPLAIN for the query you want to investigate.

     
  3. 3.

    Disable the optimizer_trace option again.

     
  4. 4.

    Retrieve the optimizer trace from the information_schema.OPTIMIZER_TRACE table.

     
The information_schema.OPTIMIZER_TRACE table includes four columns:
  • QUERY: The original query.

  • TRACE: A JSON document with the trace information. There will be more about the trace shortly.

  • MISSING_BYTES_BEYOND_MAX_MEM_SIZE: The size (in bytes) of the recorded trace is limited to the value of the optimizer_trace_max_mem_size option (defaults to 1 MiB in MySQL 8). This column shows how much more memory is required to record the full trace. If the value is greater than 0, increase the optimizer_trace_max_mem_size option with that amount.

  • INSUFFICIENT_PRIVILEGES: Whether you were missing privileges to generate the optimizer trace.

The table is created as a temporary table, so the traces are unique to the session.

Listing 20-10 shows an example of obtaining the optimizer trace for a query (the same as was used as the recurring example query in the previous sections). The optimizer trace output has been truncated here as it is more than 15000 characters and almost 500 lines long. Similarly, the output of the EXPLAIN statement has been omitted as it is the same as previously shown and it is not important for this discussion. The full output is included in the file listing_20_10.txt and the trace itself in listing_20_10.json in this book’s GitHub repository.
mysql> SET SESSION optimizer_trace = 1;
Query OK, 0 rows affected (0.0003 sec)
mysql> EXPLAIN
       SELECT ci.ID, ci.Name, ci.District,
              co.Name AS Country, ci.Population
         FROM world.city ci
              INNER JOIN
                (SELECT Code, Name
                   FROM world.country
                  WHERE Continent = 'Europe'
                  ORDER BY SurfaceArea
                  LIMIT 10
                ) co ON co.Code = ci.CountryCode
        ORDER BY ci.Population DESC
        LIMIT 5G
...
mysql> SET SESSION optimizer_trace = 0;
Query OK, 0 rows affected (0.0002 sec)
mysql> SELECT * FROM information_schema.OPTIMIZER_TRACEG
*************************** 1. row ***************************
                            QUERY: EXPLAIN
SELECT ci.ID, ci.Name, ci.District,
       co.Name AS Country, ci.Population
  FROM world.city ci
       INNER JOIN
         (SELECT Code, Name
            FROM world.country
           WHERE Continent = 'Europe'
           ORDER BY SurfaceArea
           LIMIT 10
         ) co ON co.Code = ci.CountryCode
 ORDER BY ci.Population DESC
 LIMIT 5
                            TRACE: {
...
}
MISSING_BYTES_BEYOND_MAX_MEM_SIZE: 0
          INSUFFICIENT_PRIVILEGES: 0
1 row in set (0.0436 sec)
Listing 20-10

Obtaining the optimizer trace for a query

The trace is the most interesting in the result. While there is a lot of information available, fortunately it is largely self-explanatory, and if you have familiarized yourself with the JSON-formatted EXPLAIN outputs, there are some similarities. Much of the information is regarding the cost estimates for the various parts of executing the query. Where there are multiple possible options, the optimizer calculates the cost for each choice and chooses the cheapest option. One such example from this trace is for accessing the ci (city) table. This can be done either through the CountryCode index or a table scan. The part of the trace for this decision is shown in Listing 20-11 (the indentation has been reduced).
"table": "`city` `ci`",
"best_access_path": {
  "considered_access_paths": [
    {
      "access_type": "ref",
      "index": "CountryCode",
      "rows": 18.052,
      "cost": 63.181,
      "chosen": true
    },
    {
      "rows_to_scan": 4188,
      "filtering_effect": [
      ],
      "final_filtering_effect": 1,
      "access_type": "scan",
      "using_join_cache": true,
      "buffers_needed": 1,
      "resulting_rows": 4188,
      "cost": 4194.3,
      "chosen": false
    }
  ]
},
Listing 20-11

The optimizer trace for choosing the access type for the ci table

This shows that it is estimated that on average a little more than 18 rows will be examined when using the CountryCode index ("access_type": "ref") with a cost of 63.181. For the full table scan ("access_type": "scan"), it is expected that it will be necessary to examine 4188 rows with a total cost of 4194.3. The "chosen" element shows that the ref access type has been chosen.

While it is rarely necessary to delve into the details of how the optimizer arrived at the query plan, it can be useful to learn about how the optimizer works. Occasionally, it can also be useful to see the estimated cost of other options for the query plan to understand why they are not chosen.

Tip

If you are interested in learning more about using the optimizer traces, you can read more in the MySQL internals manual at https://dev.mysql.com/doc/internals/en/optimizer-tracing.html.

Thus far, the whole discussion – except for EXPLAIN ANALYZE – has been about analyzing the query at the stage before it is executed. If you want to examine the actual performance, EXPLAIN ANALYZE is usually the best option. Another option is to use the Performance Schema.

Performance Schema Events Analysis

The Performance Schema allows you to analyze how much time is spent on each of the events that are instrumented. You can use that to analyze where time is spent when a query is executed. This section will examine how you can use the Performance Schema to analyze a stored procedure to see which of the statements in the procedure take the longest and how to use the stage events to analyze a single query. At the end of the section, it will be shown how you can use the sys.ps_trace_thread() procedure to create a diagram of work done by a thread and how you can use the ps_trace_statement_digest() to collect statistics for statements with a given digest.

Examining a Stored Procedure

It can be challenging to examine the work done by a stored procedure as you cannot use EXPLAIN directly on the procedure and it may not be obvious which queries will be executed by the procedure. Instead you can use the Performance Schema. It records each statement executed and maintains the history in the events_statements_history table .

Unless you need to store more than the last ten queries per thread, you do not need to do anything to start the analysis. If the procedure generates more than ten statement events, you will need to either increase the value of the performance_schema_events_statements_history_size option (requires a restart), use the events_statements_history_long table, or use the sys.ps_trace_thread() procedure as explained later. The remaining part of this discussion assumes you can use the events_statements_history table.

As an example of examining the queries executed by a stored procedure, consider the procedure in Listing 20-12. The procedure is also available in the file listing_20_12.sql which can be sourced into any schema.
CREATE SCHEMA IF NOT EXISTS chapter_20;
DELIMITER $$
CREATE PROCEDURE chapter_20.testproc()
    SQL SECURITY INVOKER
    NOT DETERMINISTIC
    MODIFIES SQL DATA
BEGIN
    DECLARE v_iter, v_id int unsigned DEFAULT 0;
    DECLARE v_name char(35) CHARSET latin1;
    SET v_id = CEIL(RAND()*4079);
    SELECT Name
      INTO v_name
      FROM world.city
     WHERE ID = v_id;
    SELECT *
      FROM world.city
     WHERE Name = v_name;
END$$
DELIMITER ;
Listing 20-12

An example procedure

The procedure executes three queries. The first query sets the v_id variable to an integer between 1 and 4079 (the available ID values in the world.city table). The second query fetches the name for the city with that id. The third query finds all cities with the same name as was found in the second query.

If you invoke this procedure in a connection, you can then subsequently analyze the queries triggered by the procedure and the performance of those queries. For example:
mysql> SELECT PS_CURRENT_THREAD_ID();
+------------------------+
| PS_CURRENT_THREAD_ID() |
+------------------------+
|                     83 |
+------------------------+
1 row in set (0.00 sec)
mysql> CALL chapter_20.testproc();
+------+--------+-------------+----------+------------+
| ID   | Name   | CountryCode | District | Population |
+------+--------+-------------+----------+------------+
| 2853 | Jhelum | PAK         | Punjab   |     145800 |
+------+--------+-------------+----------+------------+
1 row in set (0.0019 sec)
Query OK, 0 rows affected (0.0019 sec)

The output of the procedure is random, so will differ for each execution. You can then use the thread id found with the PS_CURRENT_THREAD_ID() function (use sys.ps_thread_id(NULL) in MySQL 8.0.15 and earlier) to determine which queries were executed.

Listing 20-13 shows how this analysis can be done. You must do this analysis in a different connection, change THREAD_ID = 83 to use the thread id you found, and change NESTING_EVENT_ID = 64 in the second query to use the event id from the first query. Some of the details have been removed from the output to focus on the values of most interest.
mysql> SELECT *
         FROM performance_schema.events_statements_history
        WHERE THREAD_ID = 83
              AND EVENT_NAME = 'statement/sql/call_procedure'
        ORDER BY EVENT_ID DESC
        LIMIT 1G
*************************** 1. row ***************************
              THREAD_ID: 83
               EVENT_ID: 64
           END_EVENT_ID: 72
             EVENT_NAME: statement/sql/call_procedure
                 SOURCE: init_net_server_extension.cc:95
            TIMER_START: 533823963611947008
              TIMER_END: 533823965937460352
             TIMER_WAIT: 2325513344
              LOCK_TIME: 129000000
               SQL_TEXT: CALL testproc()
                 DIGEST: 72fd8466a0e05fe215308832173a3be50e7edad960408c70078ef94f8ffb52b2
            DIGEST_TEXT: CALL `testproc` ( )
...
1 row in set (0.0008 sec)
mysql> SELECT *
         FROM performance_schema.events_statements_history
        WHERE THREAD_ID = 83
              AND NESTING_EVENT_ID = 64
        ORDER BY EVENT_IDG
*************************** 1. row ***************************
              THREAD_ID: 83
               EVENT_ID: 65
           END_EVENT_ID: 65
             EVENT_NAME: statement/sp/set
...
*************************** 2. row ***************************
              THREAD_ID: 83
               EVENT_ID: 66
           END_EVENT_ID: 66
             EVENT_NAME: statement/sp/set
...
*************************** 3. row ***************************
              THREAD_ID: 83
               EVENT_ID: 67
           END_EVENT_ID: 67
             EVENT_NAME: statement/sp/set
...
*************************** 4. row ***************************
              THREAD_ID: 83
               EVENT_ID: 68
           END_EVENT_ID: 68
             EVENT_NAME: statement/sp/set
...
*************************** 5. row ***************************
              THREAD_ID: 83
               EVENT_ID: 69
           END_EVENT_ID: 70
             EVENT_NAME: statement/sp/stmt
                 SOURCE: sp_head.cc:2166
            TIMER_START: 533823963993029248
              TIMER_END: 533823964065598976
             TIMER_WAIT: 72569728
              LOCK_TIME: 0
               SQL_TEXT: SELECT Name
      INTO v_name
      FROM world.city
     WHERE ID = v_id
                 DIGEST: NULL
            DIGEST_TEXT: NULL
         CURRENT_SCHEMA: db1
            OBJECT_TYPE: PROCEDURE
          OBJECT_SCHEMA: db1
            OBJECT_NAME: testproc
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: 00000
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 1
              ROWS_SENT: 0
          ROWS_EXAMINED: 1
CREATED_TMP_DISK_TABLES: 0
     CREATED_TMP_TABLES: 0
       SELECT_FULL_JOIN: 0
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 0
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 0
      SORT_MERGE_PASSES: 0
             SORT_RANGE: 0
              SORT_ROWS: 0
              SORT_SCAN: 0
          NO_INDEX_USED: 0
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: 64
     NESTING_EVENT_TYPE: STATEMENT
    NESTING_EVENT_LEVEL: 1
           STATEMENT_ID: 25241
*************************** 6. row ***************************
              THREAD_ID: 83
               EVENT_ID: 71
           END_EVENT_ID: 72
             EVENT_NAME: statement/sp/stmt
                 SOURCE: sp_head.cc:2166
            TIMER_START: 533823964067422336
              TIMER_END: 533823965880571520
             TIMER_WAIT: 1813149184
              LOCK_TIME: 0
               SQL_TEXT: SELECT *
      FROM world.city
     WHERE Name = v_name
                 DIGEST: NULL
            DIGEST_TEXT: NULL
         CURRENT_SCHEMA: db1
            OBJECT_TYPE: PROCEDURE
          OBJECT_SCHEMA: db1
            OBJECT_NAME: testproc
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 1
          ROWS_EXAMINED: 4080
CREATED_TMP_DISK_TABLES: 0
     CREATED_TMP_TABLES: 0
       SELECT_FULL_JOIN: 0
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 0
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 1
      SORT_MERGE_PASSES: 0
             SORT_RANGE: 0
              SORT_ROWS: 0
              SORT_SCAN: 0
          NO_INDEX_USED: 1
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: 64
     NESTING_EVENT_TYPE: STATEMENT
    NESTING_EVENT_LEVEL: 1
           STATEMENT_ID: 25242
6 rows in set (0.0008 sec)
Listing 20-13

Analyzing the queries executed by a stored procedure

The analysis consists of two queries. The first determines the overall information for the procedure which is done by querying for the latest occurrence (sorting by EVENT_ID) of the statement/sql/call_procedure event which is the event for calling a procedure.

The second query asks for the events for the same thread that has the event id of the statement/sql/call_procedure event as the nesting event id. These are the statements executed by the procedure. By ordering by EVENT_ID, the statements are returned in the order they are executed.

The query result of the second query shows that the procedure starts out with four SET statements. Some of these are expected, but there are also some that are triggered by implicitly setting variables. The last two rows are the most interesting for this discussion as they show that two queries were executed. First, the city table is queried by its ID column (the primary key). As expected, it examines one row. Because the result is saved in the v_name variable, the ROWS_AFFECTED counter is incremented instead of ROWS_SENT.

The second query does not perform as well. It also queries the city table but by name where there is no index. This results in 4080 rows being examined to return a single row. The NO_INDEX_USED column is set to 1 to reflect that a full table scan was performed.

One disadvantage of using this approach to examine stored procedures is that – as you can see – it can quickly use all ten rows in the history table. One alternative is to enable the events_statements_history_long consumer and test the procedure on an otherwise idle test system or disable history logging for the other connections. This allows you to analyze procedures executing up to 10000 statement events. An alternative is to use the sys.ps_trace_thread() procedure which also uses the long history but supports polling while the procedure is executing, so it can collect the events even if the table is not large enough to hold all events for the duration of the procedure.

This example has been using the statement events to analyze the performance. Sometimes you need to know what happens at a finer-grained level in which case you need to start looking at the stage events.

Analyzing Stage Events

If you need to get finer-grained details of where a query spends time, the first step is to look at the stage events. Optionally, you can also include wait events. Since the step to work with wait events is essentially the same as for stage events, it is left as an exercise for the reader to analyze the wait events for a query.

Caution

The finer-grained the events you examine, the more overhead they will have. Thus, be careful enabling stage and wait events on production systems. Some wait events, particularly related to mutexes, may also impact the query enough that they affect the conclusions of the analysis. Using wait events to analyze a query is usually something only performance architects and developers working with the MySQL source code need to do.

The number of stage events generated is much larger than the number of statement events. This means that in order to avoid the stage events disappearing from the history table, it is recommended to perform the analysis on an idle test system and to use the events_stages_history_long table . This table is disabled by default; to enable it, enable the corresponding consumer:
mysql> UPDATE performance_schema.setup_consumers
          SET ENABLED = 'YES'
        WHERE NAME IN ('events_stages_current',
                       'events_stages_history_long');
Query OK, 2 rows affected (0.0008 sec)
Rows matched: 2  Changed: 2  Warnings: 0
The events_stages_history_long consumer depends on the events_stages_current consumer, so you will need to enable both. By default, only stage events related to progress information are enabled. For a general analysis, you will want to enable all of the stage events:
mysql> UPDATE performance_schema.setup_instruments
          SET ENABLED = 'YES',
              TIMED = 'YES'
        WHERE NAME LIKE 'stage/%';
Query OK, 125 rows affected (0.0011 sec)
Rows matched: 125  Changed: 109  Warnings: 0
At this point, the analysis can proceed in much the same way as it was done when analyzing the stored procedure. For example, consider the following query being executed by the connection with the Performance Schema thread id equal to 83:
SELECT *
  FROM world.city
 WHERE Name = 'Sydney';
Assuming this is the last executed query, you can get the amount of time spent in each stage as shown in Listing 20-14. You need to execute this is a separate connection and change SET @thread_id = 83 to use the thread id for your connection. Other than the timings obviously being different, then the list of stages your query goes through may also differ.
mysql> SET @thread_id = 83;
Query OK, 0 rows affected (0.0004 sec)
mysql> SELECT EVENT_ID,
              SUBSTRING_INDEX(EVENT_NAME, '/', -1) AS Event,
              FORMAT_PICO_TIME(TIMER_WAIT) AS Latency
         FROM performance_schema.events_stages_history_long
        WHERE THREAD_ID = @thread_id
              AND NESTING_EVENT_ID = (
                  SELECT EVENT_ID
                    FROM performance_schema.events_statements_history
                   WHERE THREAD_ID = @thread_id
                   ORDER BY EVENT_ID DESC
                   LIMIT 1);
+----------+--------------------------------------+-----------+
| EVENT_ID | Event                                | Latency   |
+----------+--------------------------------------+-----------+
|     7193 | Executing hook on transaction begin. | 200.00 ns |
|     7194 | cleaning up                          | 4.10 us   |
|     7195 | checking permissions                 | 2.60 us   |
|     7196 | Opening tables                       | 41.50 us  |
|     7197 | init                                 | 3.10 us   |
|     7198 | System lock                          | 6.50 us   |
|     7200 | optimizing                           | 5.30 us   |
|     7201 | statistics                           | 15.00 us  |
|     7202 | preparing                            | 12.10 us  |
|     7203 | executing                            | 1.18 ms   |
|     7204 | end                                  | 800.00 ns |
|     7205 | query end                            | 500.00 ns |
|     7206 | waiting for handler commit           | 6.70 us   |
|     7207 | closing tables                       | 3.30 us   |
|     7208 | freeing items                        | 70.30 us  |
|     7209 | cleaning up                          | 300.00 ns |
+----------+--------------------------------------+-----------+
16 rows in set (0.0044 sec)
Listing 20-14

Finding the stages for the last statement of a connection

The event id, the stage name (removing the two first parts of the full event name for brevity), and the latency formatted with the FORMAT_PICO_TIME() function (use the sys.format_time() function in MySQL 8.0.15 and earlier) are selected from the events_stages_history_long table. The WHERE clause filters on the thread id of the connection that executed the query and by the nesting event id. The nesting event id is set to the event id of the latest executed statement for the connection with thread id equal to 83. The result shows that the slowest part of the query is Sending data which is the stage where the storage engine finds and sends the rows.

The main issue analyzing queries this way is that you are either limited by the ten events per thread saved by default or you risk the events being expunged from the long history table before you are done examining it. The sys.ps_trace_thread() procedure was created to help with that problem.

Analysis with the sys.ps_trace_thread( ) Procedure

When you need to analyze a complex query or a stored program executing more than a few statements, you can benefit from using a tool that automatically collects the information as the execution progresses. An option to do this from the sys schema is the ps_trace_thread() procedure.

The procedure loops for a period of time polling the long history tables for new transactions, statements, stages, and wait events. Optionally, the procedure can also set up the Performance Schema to include all events and enable the consumers to record the events. However, since it is usually too much to include all events, it is recommended to set up the Performance Schema yourself to instrument and consume the events that are of interest for your analysis.

Another optional feature is to reset the Performance Schema tables at the start of the monitoring. This can be great if it is acceptable to remove the content of the long history tables.

When you call the procedure, you must provide the following arguments:
  • Thread ID: The Performance Schema thread id that you want to monitor.

  • Out File: A file to write the result to. The result is created using the dot graph description language.2 This requires that the secure_file_priv option has been set to allow writing files to the target directory and the file does not exist and the user executing the procedure has the FILE privilege.

  • Max Runtime: The maximum time to monitor in seconds. There is support for specifying the value with 1/100 of a second precision. If the value is set to NULL, the runtime is set to 60 seconds.

  • Poll Interval: The interval between polling the history tables. The value can be set with the precision of 1/100 of a second. If the value is set to NULL, then the polling interval will be set to one second.

  • Refresh: A Boolean whether to reset the Performance Schema tables used for the analysis.

  • Auto Setup: A Boolean whether to enable all instruments and consumers that can be used by the procedure. When enabled, the current settings are restored when the procedure completes.

  • Debug: A Boolean whether to include additional information such as where in the source code the event is triggered. This is mostly useful when including wait events.

An example of using the ps_trace_thread() procedure can be seen in Listing 20-15. While the procedure is executing, the testproc() procedure from earlier is called from the thread that is being monitored. The example assumes you start out with the default Performance Schema settings.
Connection 1> UPDATE performance_schema.setup_consumers
                 SET ENABLED = 'YES'
               WHERE NAME = 'events_statements_history_long';
Query OK, 1 row affected (0.0074 sec)
Rows matched: 1  Changed: 1  Warnings: 0
-- Find the Performance Schema thread id for the
-- thread that will be monitored.
Connection 2> SELECT PS_CURRENT_THREAD_ID();
+-----------------+
| PS_THREAD_ID(9) |
+-----------------+
|              32 |
+-----------------+
1 row in set (0.0016 sec)
-- Replace the first argument with the thread id
-- just found.
--
-- Once the procedure returns
-- "Data collection starting for THREAD_ID = 32"
-- (replace 32 with your thread id) invoke the
-- chapter_20.testproc() chapter from connection 2.
-- The example is set to poll for 10 seconds. If you
-- need more time, change the third argument to the
-- number of seconds you need.
Connection 1> CALL sys.ps_trace_thread(
                  32,
                  '/mysql/files/thread_32.gv',
                  10, 0.1, False, False, False);
+-------------------+
| summary           |
+-------------------+
| Disabled 1 thread |
+-------------------+
1 row in set (0.0316 sec)
+---------------------------------------------+
| summary                                     |
+---------------------------------------------+
| Data collection starting for THREAD_ID = 32 |
+---------------------------------------------+
1 row in set (0.0316 sec)
-- Here, sys.ps_trace_id() blocks – execute the
-- query you want to trace. The output is random.
Connection 2> CALL chapter_20.testproc();
+------+--------+-------------+----------+------------+
| ID   | Name   | CountryCode | District | Population |
+------+--------+-------------+----------+------------+
| 3607 | Rjazan | RUS         | Rjazan   |     529900 |
+------+--------+-------------+----------+------------+
1 row in set (0.0023 sec)
Query OK, 0 rows affected (0.0023 sec)
-- Back in connection 1, wait for the sys.ps_trace_id()
-- procedure to complete.
+--------------------------------------------------+
| summary                                          |
+--------------------------------------------------+
| Stack trace written to /mysql/files/thread_32.gv |
+--------------------------------------------------+
1 row in set (0.0316 sec)
+----------------------------------------------------------+
| summary                                                  |
+----------------------------------------------------------+
| dot -Tpdf -o /tmp/stack_32.pdf /mysql/files/thread_32.gv |
+----------------------------------------------------------+
1 row in set (0.0316 sec)
+----------------------------------------------------------+
| summary                                                  |
+----------------------------------------------------------+
| dot -Tpng -o /tmp/stack_32.png /mysql/files/thread_32.gv |
+----------------------------------------------------------+
1 row in set (0.0316 sec)
+------------------+
| summary          |
+------------------+
| Enabled 1 thread |
+------------------+
1 row in set (0.0316 sec)
Query OK, 0 rows affected (0.0316 sec)
Listing 20-15

Using the ps_trace_thread() procedure

In this example, only the events_statements_history_long consumer is enabled. This will allow to record all the statement events that result for calling the testproc() procedure as it was done manually earlier. The thread id that will be monitored is obtained using the PS_CURRENT_THREAD_ID() function (in MySQL 8.0.15 and earlier, use sys.ps_thread_id(NULL)).

The ps_trace_thread() procedure is invoked for thread id 32 with the output written to /mysql/files/thread_32.gv. The procedure polls every 0.1 second for 10 seconds, and all the optional features are disabled.

You will need a program that understands the dot format to convert it into an image. One option is the Graphviz toolset which is available from several Linux distributions through the package repository. It can also be downloaded from the project’s homepage, www.graphviz.org/, for Linux, Microsoft Windows, and macOS, Solaris, and FreeBSD. The output of the procedure shows examples of how to convert the file with the dot graph definition to either a PDF or PNG file. Figure 20-13 shows the generated graph for the CALL testproc() statement .
../images/484666_1_En_20_Chapter/484666_1_En_20_Fig13_HTML.jpg
Figure 20-13

The statement graph for the CALL testproc() statement

The statement graph includes the same information as when the procedure was analyzed manually. For a procedure as simple as testproc(), the advantage of generating the graph is limited, but for more complex procedures or for analyzing queries with lower-level events enabled, it can be a good way to visualize the flow of the execution.

Another sys schema procedure that can help you analyze queries is the ps_trace_statement_digest() procedure.

Analysis with the ps_trace_statement_digest( ) Procedure

As a final example of using the Performance Schema to analyze queries, the ps_trace_statement_digest() procedure from the sys schema will be demonstrated. It takes a digest and then monitors the events_statements_history_long and events_stages_history_long tables for events related to statements with that digest. The result of the analysis includes summary data as well as details such as the query plan for the longest-running query.

The procedure takes five arguments which are all mandatory. The arguments are
  • Digest: The digest to monitor. Statements will be monitored irrespective of the default schema if their digest matches the one provided.

  • Runtime: How long to monitor for in seconds. No decimals are allowed.

  • Poll Interval: The interval between polling the history tables. The value can be set with the precision of 1/100 of a second and must be less than 1 second.

  • Refresh: A Boolean whether to reset the Performance Schema tables used for the analysis.

  • Auto Setup: A Boolean whether to enable all instruments and consumers that can be used by the procedure. When enabled, the current settings are restored when the procedure completes.

As an example, you can start monitoring with the sys.ps_trace_statement_digest() procedure and execute the following queries while the monitoring is ongoing (the example of the monitoring follows):
SELECT * FROM world.city WHERE CountryCode = 'AUS';
SELECT * FROM world.city WHERE CountryCode = 'USA';
SELECT * FROM world.city WHERE CountryCode = 'CHN';
SELECT * FROM world.city WHERE CountryCode = 'ZAF';
SELECT * FROM world.city WHERE CountryCode = 'BRA';
SELECT * FROM world.city WHERE CountryCode = 'GBR';
SELECT * FROM world.city WHERE CountryCode = 'FRA';
SELECT * FROM world.city WHERE CountryCode = 'IND';
SELECT * FROM world.city WHERE CountryCode = 'DEU';
SELECT * FROM world.city WHERE CountryCode = 'SWE';
SELECT * FROM world.city WHERE CountryCode = 'LUX';
SELECT * FROM world.city WHERE CountryCode = 'NZL';
SELECT * FROM world.city WHERE CountryCode = 'KOR';

It may vary from execution to execution which of these queries is the slowest.

Listing 20-16 shows an example of using the procedure to monitor for a query selecting all cities in a given country. In the example, the digest is found using the STATEMENT_DIGEST() function , but you may also have found it through monitoring based on the events_statements_summary_by_digest table. It will be left to the procedure to enable the instruments and consumers needed, and the monitored tables will be reset to avoid including occurrences of the statement executed before the monitoring starts. The polling frequency is set to poll every 0.5 second. To reduce the width of the output, the stage event names have had the stage/sql/ prefix removed, and the dashed lines for the EXPLAIN output have been made shorter. The unmodified output can be found in the file listing_20_16.txt in this book’s GitHub repository.
mysql> SET @digest = STATEMENT_DIGEST('SELECT * FROM world.city WHERE CountryCode = ''AUS''');
Query OK, 0 rows affected (0.0004 sec)
-- Execute your queries once the procedure has started.
mysql> CALL sys.ps_trace_statement_digest(@digest, 60, 0.5, TRUE, TRUE);
+-------------------+
| summary           |
+-------------------+
| Disabled 1 thread |
+-------------------+
1 row in set (1 min 0.0861 sec)
+--------------------+
| SUMMARY STATISTICS |
+--------------------+
| SUMMARY STATISTICS |
+--------------------+
1 row in set (1 min 0.0861 sec)
+------------+-----------+-----------+-----------+---------------+---------------+------------+------------+
| executions | exec_time | lock_time | rows_sent | rows_affected | rows_examined | tmp_tables | full_scans |
+------------+-----------+-----------+-----------+---------------+---------------+------------+------------+
|         13 | 7.29 ms   | 1.19 ms   |      1720 |             0 |          1720 |          0 |          0 |
+------------+-----------+-----------+-----------+---------------+---------------+------------+------------+
1 row in set (1 min 0.0861 sec)
+--------------------------------------+-------+-----------+
| event_name                           | count | latency   |
+--------------------------------------+-------+-----------+
| Sending data                         |    13 | 2.99 ms   |
| freeing items                        |    13 | 2.02 ms   |
| statistics                           |    13 | 675.37 us |
| Opening tables                       |    13 | 401.50 us |
| preparing                            |    13 | 100.28 us |
| optimizing                           |    13 | 66.37 us  |
| waiting for handler commit           |    13 | 64.18 us  |
| closing tables                       |    13 | 54.70 us  |
| System lock                          |    13 | 54.34 us  |
| cleaning up                          |    26 | 45.22 us  |
| init                                 |    13 | 29.54 us  |
| checking permissions                 |    13 | 23.34 us  |
| end                                  |    13 | 10.21 us  |
| query end                            |    13 | 8.02 us   |
| executing                            |    13 | 4.01 us   |
| Executing hook on transaction begin. |    13 | 3.65 us   |
+--------------------------------------+-------+-----------+
16 rows in set (1 min 0.0861 sec)
+---------------------------+
| LONGEST RUNNING STATEMENT |
+---------------------------+
| LONGEST RUNNING STATEMENT |
+---------------------------+
1 row in set (1 min 0.0861 sec)
+-----------+-----------+-----------+-----------+---------------+---------------+------------+-----------+
| thread_id | exec_time | lock_time | rows_sent | rows_affected | rows_examined | tmp_tables | full_scan |
+-----------+-----------+-----------+-----------+---------------+---------------+------------+-----------+
|        32 | 1.09 ms   | 79.00 us  |       274 |             0 |           274 |          0 |         0 |
+-----------+-----------+-----------+-----------+---------------+---------------+------------+-----------+
1 row in set (1 min 0.0861 sec)
+----------------------------------------------------+
| sql_text                                           |
+----------------------------------------------------+
| SELECT * FROM world.city WHERE CountryCode = 'USA' |
+----------------------------------------------------+
1 row in set (59.91 sec)
+--------------------------------------+-----------+
| event_name                           | latency   |
+--------------------------------------+-----------+
| Executing hook on transaction begin. | 364.67 ns |
| cleaning up                          | 3.28 us   |
| checking permissions                 | 1.46 us   |
| Opening tables                       | 27.72 us  |
| init                                 | 2.19 us   |
| System lock                          | 4.01 us   |
| optimizing                           | 5.11 us   |
| statistics                           | 46.68 us  |
| preparing                            | 7.66 us   |
| executing                            | 364.67 ns |
| Sending data                         | 528.41 us |
| end                                  | 729.34 ns |
| query end                            | 729.34 ns |
| waiting for handler commit           | 4.38 us   |
| closing tables                       | 16.77 us  |
| freeing items                        | 391.29 us |
| cleaning up                          | 364.67 ns |
+--------------------------------------+-----------+
17 rows in set (1 min 0.0861 sec)
+--------------------------------------------------+
| EXPLAIN                                          |
+--------------------------------------------------+
| {
  "query_block": {
    "select_id": 1,
    "cost_info": {
      "query_cost": "46.15"
    },
    "table": {
      "table_name": "city",
      "access_type": "ref",
      "possible_keys": [
        "CountryCode"
      ],
      "key": "CountryCode",
      "used_key_parts": [
        "CountryCode"
      ],
      "key_length": "3",
      "ref": [
        "const"
      ],
      "rows_examined_per_scan": 274,
      "rows_produced_per_join": 274,
      "filtered": "100.00",
      "cost_info": {
        "read_cost": "18.75",
        "eval_cost": "27.40",
        "prefix_cost": "46.15",
        "data_read_per_join": "19K"
      },
      "used_columns": [
        "ID",
        "Name",
        "CountryCode",
        "District",
        "Population"
      ]
    }
  }
} |
+--------------------------------------------------+
1 row in set (1 min 0.0861 sec)
+------------------+
| summary          |
+------------------+
| Enabled 1 thread |
+------------------+
1 row in set (1 min 0.0861 sec)
Query OK, 0 rows affected (1 min 0.0861 sec)
Listing 20-16

Using the ps_trace_statement_digest() procedure

The output starts out with the summary for all the queries found during the analysis. A total of 13 executions were detected using a total of 7.29 milliseconds. The overall summary also includes the aggregates for the time spent for various stages. The next part of the output are the details for the slowest of the 13 executions. The output concludes with the JSON-formatted query plan for the slowest of the queries.

There is a limitation you should be aware of for generating the query plan. The EXPLAIN statement will be executed with the default schema set to the same as where the procedure executed. That means that if the query is executed in a different schema and it does not use a fully qualified table name (i.e., including the schema name), then the EXPLAIN statement will fail, and the procedure does not output the query plan.

Summary

This chapter has covered how you can analyze queries that you believe may need optimization. The bulk of the chapter focused on the EXPLAIN statement that is the main tool for analyzing queries. The remainder of the chapter went through optimizer traces and how to use the Performance Schema to analyze queries.

The EXPLAIN statement supports several different formats that help you get the query plan in the format that works best for you. The traditional format uses a standard table output, the JSON format returns a detailed JSON document, and the tree format shows a relatively simple tree of the execution. The tree format is only supported in MySQL 8.0.16 and later and requires that the Volcano iterator executor is used to execute the query. The JSON format is what the Visual Explain feature in MySQL Workbench uses to create diagrams of the query plan.

There is a vast amount of information available about the query plan in the EXPLAIN outputs. The fields of the traditional format as well as the most commonly encountered fields of JSON were discussed. This included discussing the select types and access types and the extra information in detail. Finally, a series of examples were used to show how this information can be used.

The optimizer traces can be used to get information on how the optimizer ended up with the query plan that the EXPLAIN statement returned. It is usually not necessary to use the optimizer traces for end users, but they can be useful to learn more about the optimizer and the decision process that leads to the query plans.

The final part of the chapter showed how you can use the Performance Schema events to determine what is taking the time for a statement. It was first shown how you can break a stored procedure into individual statements and then how a statement can be broken into stages. Finally the ps_trace_thread() procedure was used to automate the analysis and create a graph of the events, and the ps_trace_statement_digest() procedure was used to collect statistics for a given statement digest.

This chapter analyzed queries. It is sometimes necessary to take the whole transaction into account. The next chapter will show how you can analyze transactions.

..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset
3.138.181.145