MySQL 8.0: Statements Latency Histograms

on

At the end we all agree that what really matters is the Query Response Time, isn’t it ?

MySQL 8.0 engineers have added more visibility in the summary tables as explained in this previous post. But to add more details, now the Performance_Schema also collects the statements latency and provide their distribution thanks to the collected histogram data.

Two tables have been added to Performance_Schema:

  • events_statements_histogram_by_digest: details about latency related to schema and query digest
  • events_statements_histogram_global: global latency summary across all schemas and queries

Let’s have a look at what we can see:

mysql> SELECT t1.SCHEMA_NAME, CONCAT(ROUND(BUCKET_QUANTILE*100,2),"% under ",
               BUCKET_TIMER_HIGH/1000000000," milliseconds") fact, 
               LEFT(QUERY_SAMPLE_TEXT,64) as QUERY_SAMPLE, t1.DIGEST, 
               COUNT(t1.DIGEST) 
               OVER(PARTITION BY t1.DIGEST) as TOT 
              FROM events_statements_histogram_by_digest t1 
              JOIN events_statements_summary_by_digest t2 
                ON t2.DIGEST = t1.DIGEST 
             WHERE COUNT_BUCKET >1 
             ORDER BY t1.DIGEST, BUCKET_TIMER_HIGH DESC 
             LIMIT 10\G
*************************** 1. row ***************************
 SCHEMA_NAME: sbtest
        fact: 86.84% under 100.0000 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 2. row ***************************
 SCHEMA_NAME: sbtest
        fact: 81.58% under 95.4993 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 3. row ***************************
 SCHEMA_NAME: sbtest
        fact: 73.68% under 87.0964 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 4. row ***************************
 SCHEMA_NAME: sbtest
        fact: 68.42% under 83.1764 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 5. row ***************************
 SCHEMA_NAME: sbtest
        fact: 63.16% under 75.8578 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 6. row ***************************
 SCHEMA_NAME: sbtest
        fact: 57.89% under 63.0957 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 7. row ***************************
 SCHEMA_NAME: sbtest
        fact: 47.37% under 50.1187 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 8. row ***************************
 SCHEMA_NAME: sbtest
        fact: 39.47% under 45.7088 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 9. row ***************************
 SCHEMA_NAME: sbtest
        fact: 26.32% under 39.8107 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
*************************** 10. row ***************************
 SCHEMA_NAME: sbtest
        fact: 18.42% under 36.3078 milliseconds
QUERY_SAMPLE: INSERT INTO sbtest1(k, c, pad) VALUES(49929, '83868641912-287739
      DIGEST: 0b515c3fcc7c2095d2b2dccf0040f79254a6fabcf96c7bb9bd597398abba69fb
         TOT: 10
10 rows in set (0.02 sec)

The LIMIT should match the amount of TOT.

We can see (row 7), that only 47.37% of this query is executed in 50ms or less and only 18.42% are executed in less than 36ms.

It’s also possible to illustrate those results like this:

mysql> SELECT CONCAT('<',ROUND(BUCKET_TIMER_HIGH/1000000000,2),'ms') as 'QRT',  
              CONCAT(RPAD('',ROUND(BUCKET_QUANTILE*100),'*'),ROUND(BUCKET_QUANTILE*100,2),"%") bar, 
              COUNT(t1.DIGEST) OVER(PARTITION BY t1.DIGEST) as TOT 
         FROM events_statements_histogram_by_digest t1 
         JOIN events_statements_summary_by_digest t2 
           ON t2.DIGEST = t1.DIGEST 
        WHERE COUNT_BUCKET >1 
        ORDER BY t1.DIGEST, BUCKET_TIMER_HIGH DESC 
             LIMIT 10;
+-----------+-----------------------------------------------------------------------------------------------+-----+
| QRT       | bar                                                                                           | TOT |
+-----------+-----------------------------------------------------------------------------------------------+-----+
| <100.00ms | ***************************************************************************************86.84% |  10 |
| <95.50ms  | **********************************************************************************81.58%      |  10 |
| <87.10ms  | **************************************************************************73.68%              |  10 |
| <83.18ms  | ********************************************************************68.42%                    |  10 |
| <75.86ms  | ***************************************************************63.16%                         |  10 |
| <63.10ms  | **********************************************************57.89%                              |  10 |
| <50.12ms  | ***********************************************47.37%                                         |  10 |
| <45.71ms  | ***************************************39.47%                                                 |  10 |
| <39.81ms  | **************************26.32%                                                              |  10 |
| <36.31ms  | ******************18.42%                                                                      |  10 |
+-----------+-----------------------------------------------------------------------------------------------+-----+
10 rows in set (0.02 sec)

Additionally to these tables, in SYS schema, we have added a procedure illustrating the latency histograms too, it’s called: ps_statement_avg_latency_histogram()

mysql> CALL sys.ps_statement_avg_latency_histogram()\G
*************************** 1. row ***************************
Performance Schema Statement Digest Average Latency Histogram: 

  . = 1 unit
  * = 2 units
  # = 3 units

(0 - 348ms)      64 | ********************************
(348 - 696ms)    7  | .......
(696 - 1044ms)   2  | ..
(1044 - 1393ms)  2  | ..
(1393 - 1741ms)  1  | .
(1741 - 2089ms)  0  | 
(2089 - 2437ms)  0  | 
(2437 - 2785ms)  0  | 
(2785 - 3133ms)  0  | 
(3133 - 3481ms)  1  | .
(3481 - 3829ms)  0  | 
(3829 - 4178ms)  0  | 
(4178 - 4526ms)  0  | 
(4526 - 4874ms)  0  | 
(4874 - 5222ms)  0  | 
(5222 - 5570ms)  0  | 

  Total Statements: 78; Buckets: 16; Bucket Size: 348 ms;

1 row in set (0.02 sec)

Query OK, 0 rows affected (0.02 sec)

As you can see, MySQL 8.0 added more visibility in many domains to analyze and understand better your workload.

 

Subscribe to Blog via Email

Enter your email address to subscribe to this blog and receive notifications of new posts by email.

2 thoughts on “MySQL 8.0: Statements Latency Histograms

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.

recent
categories