0

Faciliter la lecture des mesures de temps dans performance_schema

twitterlinkedinmail

Admettons que nous devions remonter pour une base mysql donnée le top 10 des tables les plus accédées en lecture par temps d’accès. On pourrait utiliser P_S.table_io_waits_summary_by_table par exemple :

mysql> select OBJECT_NAME, INDEX_NAME, COUNT_READ, AVG_TIMER_READ
    -> from performance_schema.table_io_waits_summary_by_index_usage
    -> where OBJECT_SCHEMA='mabase'
    -> order by AVG_TIMER_READ desc limit 10 ;
+---------------+------------+------------+----------------+
| OBJECT_NAME   | INDEX_NAME | COUNT_READ | AVG_TIMER_READ |
+---------------+------------+------------+----------------+
| t_1           | idx3       |          1 |       70377507 |
| t_1           | PRIMARY    |          6 |       20655678 |
| t_2           | PRIMARY    |         10 |        3984852 |
| t_2           | idx3       |         76 |        2099178 |
| t_3           | NULL       |        156 |         894048 |
| t_4           | PRIMARY    |      92726 |         525003 |
| t_3           | idx2       |          0 |              0 |
| t_3           | idx4       |          0 |              0 |
| t_3           | idx5       |          0 |              0 |
| t_1           | idx2       |          0 |              0 |
+---------------+------------+------------+----------------+
10 rows in set (1.07 sec)

Bon c’est bien gentil mais on ne sait pas à priori quelle sera l’unité utilisée pour exprimer cette valeur de AVG_TIMER_READ. Sont-ce des microsecondes, des nanosecondes … La documentation sur la vue ne le dit pas.

La gestion des timers dans performance_schema

Ce pourra faire l’objet d’un autre post, mais pour simplifier on peut dire que les vues dans performance_schema obéissent à une hiérarchie basée sur des instruments et des consumers.

Globalement, les instruments sont les évènements que l’on veut tracer, et les consumers les destinations de trace. Si on veut faire l’analogie avec les Extended Events de SQL Server, on peut dire que les instruments sont les events et les consumers les targets. Sauf que pour MySQL, les destinations sont toutes des vues.

Les classes principales ci-dessous transaction, statement, stage, wait et idle sont associées à de la mesure de temps :

Statement est une requête unitaire, faisant partie d’une transaction.
Stage représente chaque étape lors de l’exécution d’un statement: parsing, ouverture de la table, etc… Tout le monde connaît l’infame Copying to tmp table, et bien c’est un stage.
Wait regroupe tous les postes d’attente : les IO sur les fichiers de table IBD, les fichiers MyISAM, les redologs, les datafiles InnoDB, etc…
Si bien que ces 3 classes sont imbriquées les unes dans les autres, avec la classe transaction qui est la classe la plus haute dans la hiérarchie:

Tout ça pour dire que nos classes principales ont un besoin de mesurer le temps avec une granularité différente selon l’ordre de grandeur de ce que l’on mesure: l’ordre de mesure de l’exécution d’une requête peut se trouver entre la milliseconde et la seconde, alors que celui pour mesurer le temps d’attente sur un mutex, serait plutôt de l’ordre de la nanoseconde, voire du cycle.

Ca tombe bien, tout ça est très bien organisé, et on dispose dans P_S de tables de configuration pour nous indiquer quelle unité de temps est utilisée pour quelle classe:

mysql> select * from performance_schema.setup_timers ;
+-------------+-------------+
| NAME        | TIMER_NAME  |
+-------------+-------------+
| idle        | MICROSECOND |
| wait        | CYCLE       |
| stage       | NANOSECOND  |
| statement   | NANOSECOND  |
| transaction | NANOSECOND  |
+-------------+-------------+

Sys pour se simplifier la vie

Le problème c’est que la vue que l’on utilise (table_io_waits_summary_by_index_usage) ne fait pas partie de la hiérarchie classique stage / statement / wait, donc on n’est pas plus avancé.

Or depuis la version 5.7.7, le très bon Mark Leith d’Oracle nous a gratifié du schéma sys qui doit simplifier les arcanes compliquées de P_S et en accélérer l’adoption.

En fouillant un peu dans le code des vues, on retrouve une invocation à une fonction format_time() appliquée aux colonnes de temps de table_io_waits_summary_by_table, par exemple dans la définition de sys.schema_table_statistics :

mysql> show create table schema_table_statistics \G
*************************** 1. row ***************************
                View: schema_table_statistics
         Create View: CREATE algorithm=temptable definer=`mysql.sys`@`localhost` SQL security invoker view `schema_table_statistics`
AS 
  SELECT    `pst`.`object_schema`                                    AS `table_schema`, 
            `pst`.`object_name`                                      AS `table_name`, 
            `sys`.`format_time`(`pst`.`sum_timer_wait`)              AS `total_latency`, 
            `pst`.`count_fetch`                                      AS `rows_fetched`, 
            `sys`.`format_time`(`pst`.`sum_timer_fetch`)             AS `fetch_latency`, 
            `pst`.`count_insert`                                     AS `rows_inserted`, 
            `sys`.`format_time`(`pst`.`sum_timer_insert`)            AS `insert_latency`, 
            `pst`.`count_update`                                     AS `rows_updated`, 
            `sys`.`format_time`(`pst`.`sum_timer_update`)            AS `update_latency`, 
            `pst`.`count_delete`                                     AS `rows_deleted`, 
            `sys`.`format_time`(`pst`.`sum_timer_delete`)            AS `delete_latency`, 
            `fsbi`.`count_read`                                      AS `io_read_requests`, 
            `sys`.`format_bytes`(`fsbi`.`sum_number_of_bytes_read`)  AS `io_read`, 
            `sys`.`format_time`(`fsbi`.`sum_timer_read`)             AS `io_read_latency`, 
            `fsbi`.`count_write`                                     AS `io_write_requests`, 
            `sys`.`format_bytes`(`fsbi`.`sum_number_of_bytes_write`) AS `io_write`, 
            `sys`.`format_time`(`fsbi`.`sum_timer_write`)            AS `io_write_latency`, 
            `fsbi`.`count_misc`                                      AS `io_misc_requests`, 
            `sys`.`format_time`(`fsbi`.`sum_timer_misc`)             AS `io_misc_latency` 
  FROM      (`performance_schema`.`table_io_waits_summary_by_table` `pst` 
            LEFT JOIN `sys`.`x$ps_schema_table_statistics_io` `fsbi` 
            ON       ((( `pst`.`object_schema` = `fsbi`.`table_schema`) 
            AND       ( `pst`.`object_name` = `fsbi`.`table_name`)))) 
  ORDER BY  `pst`.`sum_timer_wait` DESC
character_set_client: utf8
collation_connection: utf8_general_ci
1 row in set (0.00 sec)

Voyons un peu la définition de cette fonction format_time() :

mysql> select ROUTINE_NAME, ROUTINE_BODY, ROUTINE_DEFINITION
    -> from information_schema.routines
    -> where routine_schema='sys' and ROUTINE_NAME='format_time' \G
*************************** 1. row ***************************
      ROUTINE_NAME: format_time
      ROUTINE_BODY: SQL
ROUTINE_DEFINITION: 
BEGIN 
  IF picoseconds IS NULL THEN 
    RETURN NULL; 
  ELSEIF picoseconds >= 604800000000000000 THEN 
    RETURN CONCAT(Round(picoseconds / 604800000000000000, 2), ' w'); 
  ELSEIF picoseconds >= 86400000000000000 THEN 
    RETURN CONCAT(Round(picoseconds / 86400000000000000, 2), ' d'); 
  ELSEIF picoseconds >= 3600000000000000 THEN 
    RETURN CONCAT(Round(picoseconds / 3600000000000000, 2), ' h'); 
  ELSEIF picoseconds >= 60000000000000 THEN 
    RETURN CONCAT(Round(picoseconds / 60000000000000, 2), ' m'); 
  ELSEIF picoseconds >= 1000000000000 THEN 
    RETURN CONCAT(Round(picoseconds / 1000000000000, 2), ' s'); 
  ELSEIF picoseconds >= 1000000000 THEN 
    RETURN CONCAT(Round(picoseconds / 1000000000, 2), ' ms'); 
  ELSEIF picoseconds >= 1000000 THEN 
    RETURN CONCAT(Round(picoseconds / 1000000, 2), ' us'); 
  ELSEIF picoseconds >= 1000 THEN 
    RETURN CONCAT(Round(picoseconds / 1000, 2), ' ns'); 
  ELSE 
    RETURN CONCAT(picoseconds, ' ps'); 
  END IF; 
END 
1 row in set (0.03 sec)

la fonction part du principe qu’on lui passe des picosecondes. On en déduit donc que le temps hors ‘timers’ sera exprimé dans la mesure la plus petite, soit des picosecondes.

D’ailleurs, si vous êtes en 5.7.7 minimum, et que vous souhaitez résoudre simplement cette question de mesure, vous pouvez utiliser la fonction directement sur les vues de P_S:

mysql> select OBJECT_NAME, INDEX_NAME, COUNT_READ, sys.format_time(AVG_TIMER_READ)
    -> from performance_schema.table_io_waits_summary_by_index_usage
    ->  where OBJECT_SCHEMA='mabase'
    -> order by AVG_TIMER_READ desc limit 10 ;
+-------------------+-------------------+------------+---------------------------------+
| OBJECT_NAME       | INDEX_NAME        | COUNT_READ | sys.format_time(AVG_TIMER_READ) |
+-------------------+-------------------+------------+---------------------------------+
| t_1               | idx3              |         88 | 33.52 us                        |
| t_1               | PRIMARY           |        180 | 26.55 us                        |
| t_2               | PRIMARY           |         49 | 25.95 us                        |
| t_2               | idx3              |         26 | 23.71 us                        |
| t_3               | NULL              |         94 | 21.76 us                        |
| t_4               | PRIMARY           |          1 | 21.21 us                        |
| t_3               | idx2              |          1 | 19.58 us                        |
| t_3               | idx4              |          1 | 18.83 us                        |
| t_3               | idx5              |         18 | 15.86 us                        |
| t_1               | idx2              |          1 | 14.91 us                        |
+-------------------+-------------------+------------+---------------------------------+
10 rows in set (1.34 sec)

Et c’est tout pour aujourd’hui, bon weekend à toutes et tous et à bientôt !
~David.

Continuez votre lecture sur le blog :

twitterlinkedinmail

David Baffaleuf

Laisser un commentaire

Votre adresse de messagerie ne sera pas publiée. Les champs obligatoires sont indiqués avec *

Ce site utilise Akismet pour réduire les indésirables. En savoir plus sur comment les données de vos commentaires sont utilisées.