performance_schema — мощный встроенный в MySQL инструмент, который вы можете использовать для анализа запросов, производительности и, как следствие, для улучшения производительности базы данных.

По своей сути, performance_schema, это автоматически созданная MySQL база данных, которая внутри себя содержит множество служебных таблиц, в которые MySQL любезно пишет данные.

Если вы подключитесь к mysql-серверу и посмотрите, какие базы данных имеются: show databases

mysql> show databases;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| mysql              |
| performance_schema |
| sys                |
| test               |
+--------------------+
5 rows in set (0.00 sec)

вы увидите что одна из баз данных — performance_schema. Давайте посмотрим что имеется в этой базе данных и чем она может помочь в поиске проблем производительности.

Note: если вы не видите performance_schema базу данных в списке баз данных, это значит, что для текущего пользователя не достаточно прав для доступа к ней, подключитесь под root.

Взглянем, что имеется внутри базы данных:

mysql> use performance_schema;
Database changed
mysql> show tables;
+------------------------------------------------------+
| Tables_in_performance_schema                         |
+------------------------------------------------------+
| accounts                                             |
| cond_instances                                       |
| events_stages_current                                |
| events_stages_history                                |
| events_stages_history_long                           |
| events_stages_summary_by_account_by_event_name       |
| events_stages_summary_by_host_by_event_name          |
| events_stages_summary_by_thread_by_event_name        |
| events_stages_summary_by_user_by_event_name          |
| events_stages_summary_global_by_event_name           |
| events_statements_current                            |
| events_statements_history                            |
| events_statements_history_long                       |
| events_statements_summary_by_account_by_event_name   |
| events_statements_summary_by_digest                  |
| events_statements_summary_by_host_by_event_name      |
| events_statements_summary_by_program                 |
| events_statements_summary_by_thread_by_event_name    |
| events_statements_summary_by_user_by_event_name      |
| events_statements_summary_global_by_event_name       |
| events_transactions_current                          |
| events_transactions_history                          |
| events_transactions_history_long                     |
| events_transactions_summary_by_account_by_event_name |
| events_transactions_summary_by_host_by_event_name    |
| events_transactions_summary_by_thread_by_event_name  |
| events_transactions_summary_by_user_by_event_name    |
| events_transactions_summary_global_by_event_name     |
| events_waits_current                                 |
| events_waits_history                                 |
| events_waits_history_long                            |
| events_waits_summary_by_account_by_event_name        |
| events_waits_summary_by_host_by_event_name           |
| events_waits_summary_by_instance                     |
| events_waits_summary_by_thread_by_event_name         |
| events_waits_summary_by_user_by_event_name           |
| events_waits_summary_global_by_event_name            |
| file_instances                                       |
| file_summary_by_event_name                           |
| file_summary_by_instance                             |
| global_status                                        |
| global_variables                                     |
| host_cache                                           |
| hosts                                                |
| memory_summary_by_account_by_event_name              |
| memory_summary_by_host_by_event_name                 |
| memory_summary_by_thread_by_event_name               |
| memory_summary_by_user_by_event_name                 |
| memory_summary_global_by_event_name                  |
| metadata_locks                                       |
| mutex_instances                                      |
| objects_summary_global_by_type                       |
| performance_timers                                   |
| prepared_statements_instances                        |
| replication_applier_configuration                    |
| replication_applier_status                           |
| replication_applier_status_by_coordinator            |
| replication_applier_status_by_worker                 |
| replication_connection_configuration                 |
| replication_connection_status                        |
| replication_group_member_stats                       |
| replication_group_members                            |
| rwlock_instances                                     |
| session_account_connect_attrs                        |
| session_connect_attrs                                |
| session_status                                       |
| session_variables                                    |
| setup_actors                                         |
| setup_consumers                                      |
| setup_instruments                                    |
| setup_objects                                        |
| setup_timers                                         |
| socket_instances                                     |
| socket_summary_by_event_name                         |
| socket_summary_by_instance                           |
| status_by_account                                    |
| status_by_host                                       |
| status_by_thread                                     |
| status_by_user                                       |
| table_handles                                        |
| table_io_waits_summary_by_index_usage                |
| table_io_waits_summary_by_table                      |
| table_lock_waits_summary_by_table                    |
| threads                                              |
| user_variables_by_thread                             |
| users                                                |
| variables_by_thread                                  |
+------------------------------------------------------+
87 rows in set (0.00 sec)

events_statements_history_long

Давайте запустим следующий запрос к таблице events_statements_history_long и посмотрим на результат:

SELECT *,ROUND(timer_wait)*10e-10 as `execution (ms)` FROM events_statements_history_long
  WHERE timer_wait>100000000000 OR NO_INDEX_USED=1 OR CREATED_TMP_TABLES >= 2 
        OR ROWS_EXAMINED>=50000
  ORDER BY timer_wait DESC LIMIT 10\G

mysql> SELECT *,ROUND(timer_wait)*10e-10 as `execution (ms)` FROM events_statements_history_long_2019_05_16   WHERE timer_wait>100000000000 OR NO_INDEX_USED=1 OR CREATED_TMP_TABLES >= 2          OR ROWS_EXAMINED>=50000   ORDER BY timer_wait DESC LIMIT 2\G
*************************** 1. row ***************************
              THREAD_ID: 69003684
               EVENT_ID: 2
           END_EVENT_ID: 2
             EVENT_NAME: statement/sql/select
                 SOURCE: mysqld.cc:962
            TIMER_START: 2308419211743374000
              TIMER_END: 2308495709540542000
             TIMER_WAIT: 76497797168000
              LOCK_TIME: 76497749000000
               SQL_TEXT: SELECT o0_.order_id AS order_id_0, o0_.system_message AS system_message_1, o0_.added AS added_2, o0_.tracking_no AS tracking_no_3, o0_.user_id AS user_id_4, o0_.VendorTxCode AS VendorTxCode_5, o0_.delivery_price AS delivery_price_6, o0_.discount AS discount_7, o0_.total_price AS total_price_8, o0_.vat_value AS vat_value_9, o0_.provider AS provider_10, o0_.order_progress_id AS order_progress_id_11, o0_.shipping_address_id AS shipping_address_id_12, o0_.billing_address_id AS billing_address_id_13 FROM orders o0_ INNER JOIN orders_status_history o1_ ON o0_.order_id = o1_.order_id WHERE o1_.changed >= '2019-05-15 00:00:00' AND o1_.changed <= '2019-05-15 23:59:59' AND o1_.status = 3
                 DIGEST: 688ba10d86cc440c02cfb7ef1c6c9975
            DIGEST_TEXT: SELECT `o0_` . `order_id` AS `order_id_0` , `o0_` . `system_message` AS `system_message_1` , `o0_` . `added` AS `added_2` , `o0_` . `tracking_no` AS `tracking_no_3` , `o0_` . `user_id` AS `user_id_4` , `o0_` . `VendorTxCode` AS `VendorTxCode_5` , `o0_` . `delivery_price` AS `delivery_price_6` , `o0_` . `discount` AS `discount_7` , `o0_` . `total_price` AS `total_price_8` , `o0_` . `vat_value` AS `vat_value_9` , `o0_` . `provider` AS `provider_10` , `o0_` . `order_progress_id` AS `order_progress_id_11` , `o0_` . `shipping_address_id` AS `shipping_address_id_12` , `o0_` . `billing_address_id` AS `billing_address_id_13` FROM `orders` `o0_` INNER JOIN `orders_status_history` `o1_` ON `o0_` . `order_id` = `o1_` . `order_id` WHERE `o1_` . `changed` >= ? AND `o1_` . `changed` <= ? AND `o1_` . `status` = ? 
         CURRENT_SCHEMA: secretsales
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 663
          ROWS_EXAMINED: 15624270
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: NULL
     NESTING_EVENT_TYPE: NULL
               ADDED_AT: 2019-05-16 02:06:22
         execution (ms): 76497.797168
*************************** 2. row ***************************
              THREAD_ID: 71318267
               EVENT_ID: 6
           END_EVENT_ID: 6
             EVENT_NAME: statement/sql/select
                 SOURCE: mysqld.cc:962
            TIMER_START: 2359118730136491000
              TIMER_END: 2359178166965149000
             TIMER_WAIT: 59436828658000
              LOCK_TIME: 59436703000000
               SQL_TEXT: SELECT
                products.id AS product_id,
                pm.name AS product_name,
                products.ref AS product_code,
                product.ean AS product_ean,
                pm.id AS product_master_id,
                products.category_id,
                products.brand_id,
                products.gender,
                category.name AS category_name,
                brands.name AS brand_name,
                brands.slug AS brand_slug,
                product_options.our_price AS online_price,
                product_options.rrp_price AS rrp_price,
                products.supp_ref as supplier_ref,
                products.store_price,
                pm.short_description,
                pm.description,
                pm.slug,
                COALESCE(
                    (SELECT
                        COALESCE(SUM(od.quantity), 0) - COALESCE(SUM(od.returned_quantity), 0)
                    FROM
                        order_details od
                    WHERE
                ...
                 DIGEST: 94e333d078b88fc028cecc9c86c9bb25
            DIGEST_TEXT: SELECT `products` . `id` AS `product_id` , `pm` . `name` AS `product_name` , `products` . `ref` AS `product_code` , `product` . `ean` AS `product_ean` , `pm` . `id` AS `product_master_id` , `products` . `category_id` , `products` . `brand_id` , `products` . `gender` , `category` . `name` AS `category_name` , `brands` . `name` AS `brand_name` , `brands` . `slug` AS `brand_slug` , `product_options` . `our_price` AS `online_price` , `product_options` . `rrp_price` AS `rrp_price` , `products` . `supp_ref` AS `supplier_ref` , `products` . `store_price` , `pm` . `short_description` , `pm` . `description` , `pm` . `slug` , COALESCE ( ( SELECT COALESCE ( SUM ( `od` . `quantity` ) , ? ) - COALESCE ( SUM ( `od` . `returned_quantity` ) , ? ) FROM `order_details` `od` WHERE `od` . `product_id` = `products` . `id` GROUP BY `products` . `id` ) , ? ) AS `units_sold` , COALESCE ( ( SELECT SUM ( `po2` . `stock` ) FROM `product_options` `po2` WHERE `po2` . `product_id` = `products` . `id` GROUP BY `products` . `id` ) , ? ) AS 
         CURRENT_SCHEMA: secretsales
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 7759
          ROWS_EXAMINED: 48535066
CREATED_TMP_DISK_TABLES: 0
     CREATED_TMP_TABLES: 2
       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: 11588
              SORT_SCAN: 15518
          NO_INDEX_USED: 0
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: NULL
     NESTING_EVENT_TYPE: NULL
               ADDED_AT: 2019-05-16 16:11:01
         execution (ms): 59436.828658000006
2 rows in set (1.33 sec)

Здесь мы выбрали несколько из последних 10k запросов, которые пришли в базу данных с сортировкой по времени выполнения. Так как мы сделали сортировку по TIMER_WAIT DESC, то мы получили запросы, которые дольше всего выполнялись базой данных (в моем запросе - время в мс). TIMER_WAIT - есть время между TIMER_START и TIMER_END. 

Настраиваем Import из events_statements_history_long

Таблица events_statements_history_long работает как стэк, в ней всегда хранится 10k последних выполненных запросов. Таким образом, если нам нужна постоянная статистика по проблемных запросам, нужно настроить импорт записей из базы performance_schema в свою отдельную базу данных. Как часто нужно делать импорт - зависит от того, насколько много запросов обрабатывается вашей базой в единицу времени. Например, если в секунду MySQL-сервер выполняет 1-2к запросов, то имеет смысл делать импорт медленных запросов каждые 5-10 секунд, чтобы не пропустить ничего важного.

После того, как мы настроили постоянный import (например, по cron), мы можем начать заниматься анализом и аггрегацией.

Давайте рассмотрим подробнее какая информация имеется в MySQL о каждом из запросов.

Для анализа конкретного запроса по его хэшу (по DIGEST) можно использовать запрос:

mysql> select min(ROUND(timer_end - timer_start)*10e-10),max(ROUND(timer_end - timer_start)*10e-10),avg(ROUND(timer_end - timer_start)*10e-10),count(*), min(ROWS_EXAMINED), max(ROWS_EXAMINED), avg(ROWS_EXAMINED), min(ROWS_SENT), max(ROWS_SENT), avg(ROWS_SENT) from events_statements_history_long_2019_04_26 where digest='94e333d078b88fc028cecc9c86c9bb25'\G;
*************************** 1. row ***************************
min(ROUND(timer_end - timer_start)*10e-10): 0.7938240000000001
max(ROUND(timer_end - timer_start)*10e-10): 56825.158007000005
avg(ROUND(timer_end - timer_start)*10e-10): 486.51505451270094
count(*): 2362
min(ROWS_EXAMINED): 38
max(ROWS_EXAMINED): 48241082
avg(ROWS_EXAMINED): 417941.6054
min(ROWS_SENT): 1
max(ROWS_SENT): 7835
avg(ROWS_SENT): 189.1384
1 row in set (0.70 sec)

По умолчанию, статистика в perfromance_shchema выключена. Иными словами — таблица events_statements_history_long пуста. Чтобы контролировать запросы в режиме реального времени в perfromance_shchema, нужно обновить setup_instruments и setup_consumers таблицы.

Включить мониторинг perfromance_shchema:

UPDATE performance_schema.setup_instruments
  SET ENABLED = 'YES', TIMED = 'YES'
  WHERE NAME LIKE 'statement/%';

UPDATE performance_schema.setup_consumers
  SET ENABLED = 'YES'
  WHERE NAME LIKE '%statements%';

Выключить мониторинг:

UPDATE performance_schema.setup_instruments
  SET ENABLED = 'NO', TIMED = 'NO'
  WHERE NAME LIKE 'statement/%';

UPDATE performance_schema.setup_consumers
  SET ENABLED = 'NO'
  WHERE NAME LIKE '%statements%';