Séb.

L'exécution d'une procédure stockée SQL est souvent obscure, et c'est le moins qu'on puisse dire. Il peut être utile de suivre son activité afin d'identifier des points de ralentissement à retravailler.

À l'aide des fonctionnalités offertes par MySQL 8 (peut-être également ses prédécesseurs, et même d'autres SGBD), voici une solution légère et simple à mettre en place grâce à une table temporaire, une colonne temporelle autovalorisée et une colonne générée.

Table report à créer dans la procédure stockée :

Code SQL :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
CREATE TEMPORARY TABLE report (
    id INT UNSIGNED AUTO_INCREMENT PRIMARY_KEY,
    action TINYTEXT,
    begin DATETIME(6),
    end DATETIME(6) DEFAULT CURRENT_TIMESTAMP,
    duration TIME(6) AS (TIMEDIFF(end, begin))
);

Grâce au mot-clef TEMPORARY, la table report n'existera que le temps de la session et sera ensuite automatiquement détruite.

La colonne id permet surtout d'afficher un numéro de ligne, action de décrire la mesure.

La colonne end sera valorisée automatiquement lors de l'insertion d'une nouvelle entrée grâce à DEFAULT CURRENT_TIMESTAMP.

La colonne générée duration, mesurant la durée de l'action, est calculée automatiquement avec TIMEDIFF() selon les colonnes begin et end de la ligne.

Pour un rapport précis, toutes les colonnes temporelles ont une précision à la microseconde

Voici un exemple d'application :

Code SQL :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
DELIMITER ;;
CREATE PROCEDURE upkeep_database()
COMMENT 'Une bonne grosse procédure, qui prend du temps...'
BEGIN
    CREATE TEMPORARY TABLE report (
        id INT UNSIGNED AUTO_INCREMENT PRIMARY_KEY,
        action TINYTEXT NOT NULL,
        begin DATETIME(6) NOT NULL,
        end DATETIME(6) DEFAULT CURRENT_TIMESTAMP,
        duration TIME(6) AS (TIMEDIFF(end, begin))
    );
 
    SET @begin = NOW(6);
    CALL import_data();
    INSERT INTO report VALUES ('Import des données', @begin);
 
    SET @begin = NOW(6);
    CALL update_table1();
    INSERT INTO report VALUES ('Mise à jour de table1', @begin);
 
    SET @begin = NOW(6);
    CALL update_table2();
    INSERT INTO report VALUES ('Mise à jour de table2', @begin);
 
    SELECT ALL * FROM report ORDER BY id ASC;
END;;

L'exécution de upkeep_database() produira un rapport comme :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
+----+-----------------------+----------------------------+----------------------------+-----------------+
| id | action                | begin                      | end                        | duration        |
+----+-----------------------+----------------------------+----------------------------+-----------------+
|  1 | Import des données    | 2022-04-02 14:12:37.760431 | 2022-04-02 14:12:51.465991 | 00:00:13.705560 |
|  2 | Mise à jour de table1 | 2022-04-02 14:12:51.490081 | 2022-04-02 14:19:01.533033 | 00:06:10.042952 |
|  3 | Mise à jour de table2 | 2022-04-02 14:19:01.559302 | 2022-04-02 14:19:06.095999 | 00:00:04.536697 |
+----+-----------------------+----------------------------+----------------------------+-----------------+

On voit immédiatement que la tâche la plus longue est Mise à jour de table1 avec 6 min. 10 sec.

Pour une lecture encore meilleure, ajoutons un peu d'analyse avec les fonctions fenêtrées.

Afin d'obtenir un temps cumulé d'exécution et la part du temps d'exécution total de chaque tâche, remplaçons le SELECT final par :

Code SQL :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
SELECT ALL
    id, begin, end, duration,
    CAST(SUM(duration) OVER (ORDER BY id ASC) AS TIME(6)) AS total,
    duration / SUM(duration) OVER () AS share
FROM report;

Cela donne :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
+----+-----------------------+----------------------------+----------------------------+-----------------+-----------------+--------------+
| id | action                | begin                      | end                        | duration        | total           | share        |
+----+-----------------------+----------------------------+----------------------------+-----------------+-----------------+--------------+
|  1 | Import des données    | 2022-04-02 14:12:37.760431 | 2022-04-02 14:12:51.465991 | 00:00:13.705560 | 00:00:13.705560 | 0.0218142331 |
|  2 | Mise à jour de table1 | 2022-04-02 14:12:51.490081 | 2022-04-02 14:19:01.533033 | 00:06:10.042952 | 00:06:23.748512 | 0.9709650064 |
|  3 | Mise à jour de table2 | 2022-04-02 14:19:01.559302 | 2022-04-02 14:19:06.095999 | 00:00:04.536697 | 00:06:28.285209 | 0.0072207605 |
+----+-----------------------+----------------------------+----------------------------+-----------------+-----------------+--------------+

Nous voici informés que upkeep_database() a été exécutée en 6 min. 28 sec. et que la tâche Mise à jour de table1 représente 97% du temps d'exécution total. Il est donc urgent de revoir cette tâche

Comme attendu, en fin de session la table report est automatiquement détruite, libérant la place pour de futures utilisations.

Et voilà pour le rapport d'exécution et ces quelques fonctionnalités SQL bien pratiques au quotidien.