Instructions préparées

Instructions préparées - partie 1

Si on part d’Oracle...

      Le travail effectué par un SGBD sur une requête ne se limite pas à l’exécuter. Préalablement, il comprend notamment une vérification syntaxique, une vérification sémantique de l’existence des objets et des privilèges, la recherche du meilleur plan d’exécution par le planificateur (optimiseur). La phase préalable est globalement appelée PARSE, viennent ensuite les phases d’EXECUTE (exécution de la requête) et de FETCH (ramener les résultats).
      La planification (ou optimisation) peut prendre du temps et Oracle Database impose une solution sur cet aspect. Les plans sont en effet stockés dans une zone mémoire appelée la shared pool. Si une requête a déjà été rencontrée et que son plan est encore en mémoire partagée alors le PARSE est potentiellement SOFT (voire SOFTER si notre session dispose d’un pointeur vers l’emplacement du plan dans la zone partagée). Sinon il est HARD. Le partage des curseurs est un aspect très important de ce SGBD. Même si Oracle fournit des contournements côté serveur, ne pas utiliser de variables (bind variables) au niveau des requêtes lors du développement est à la fois une faille de sécurité ET un facteur limitant sévèrement la montée en charge.
      Sur le papier, cette architecture est intéressante. Mais elle présente plusieurs inconvénients. La mémoire allouée peut être insuffisante jusqu’à obtenir l’ORA-4031 bien connue des DBA Oracle. Un autre problème est que le plan peut être optimal pour certaines valeurs des variables et pas pour d’autres. Conscients de ces inconvénients, les développeurs d’Oracle tentent d’introduire version après version des contrepoisons : allocation dynamique de mémoire entre les différentes zones pour retarder l’ORA-4031, bind peeking puis adaptive cursor sharing pour obtenir le bon plan en toutes circonstances etc.
      Tout cela est très complexe mais, qu’il soit HARD, SOFT ou SOFTER, le PARSE idéal est encore celui qui n’est pas effectué comme le rappelle ici Tom Kyte.
      C’est un conseil assez général. La meilleure façon d’optimiser une opération est de ne pas la faire. Une application transactionnelle fonctionnant avec Oracle montera très difficilement en charge si le taux de soft parses par rapport aux parses n’est pas assez élevé mais elle ne sera complètement optimisée que si le taux d’exécutions par rapport aux parses (EXECUTE TO PARSE) est lui aussi élevé.

Quid de PostgreSQL ?

L'architecture proposée par PostgreSQL est plus simple. Le planificateur est léger, rendant moins utile l’existence d'une zone mémoire partagée permettant d'éviter les "hard parses". Quels avantages ?

Vous ne risquez pas l’équivalent de l’ORA-4031 et une quantité plus importante de mémoire peut être utilisée pour le cache des données

Vous ne risquez pas d’obtenir un plan d’exécution qui n’est pas optimal pour votre requête

Beaucoup moins de problèmes potentiels mais un point peut cependant être soulevé. Est-il intéressant de respecter le principe PARSE ONCE / EXECUTE MANY ? Economiser la phase de PARSE consiste avec PostgreSQL à préparer les instructions, cette préparation étant spécifique à une session. A noter que ce qui est ensuite toujours économisé est le PARSE. L’économie n’inclut pas systématiquement la planification du plan d’exécution, cet aspect sera étudié dans une autre page.
Un cadre commun est fixé pour l’ensemble des tests avec la table GEANTS comprenant 1 million de lignes et faisant autour d’1Go :

select version(); version --------------------------------------------------------------------------------------------------------------------------- PostgreSQL 10.1 on x86_64-pc-linux-gnu (Debian 10.1-2.pgdg90+1), compiled by gcc (Debian 6.3.0-18) 6.3.0 20170516, 64-bit (1 ligne) create table geants( idg integer generated always as identity primary key, genre char(1), taille smallint, masse smallint, actif boolean, devise varchar(128), pw smallint, heureux boolean, couleur varchar(8), veteran boolean, clan smallint, gabarit varchar(8), revenu integer, pm smallint, berserk boolean, tutelaire smallint, ere varchar(10), cyclope boolean); CREATE TABLE WITH serie(i, r1) AS (SELECT generate_series(1,10000000,1), random()) insert into geants(genre, taille, masse, actif, devise, pw, heureux, couleur, veteran, clan, gabarit, revenu, pm, berserk, tutelaire, ere, cyclope) select case when random() < 0.45 then 'M' else 'F' end, 200 + (trunc(random() * 200 + 1)), 300 + (trunc(random() * 200 + 1)), case when random() < 0.01 then false when random() > 0.5 and random() < 0.99 then false else true end, upper(md5(random()::text)), (trunc(random()*100 + 1)), case when random() < 0.1 then false else true end, case when r1 <= 0.29998 then 'GRIS' when r1 <= 0.59998 then 'NOIR' else 'BLEU' end, case when random() < 0.9 then false else true end, (trunc(random()*1000 + 1)), case when r1 <= 0.29999 then 'PETIT' when r1 <= 0.59999 then 'MOYEN' else 'GRAND' end, (trunc(random()*1000000 + 1)), (trunc(random()*10 + 1)), case when r1 <= 0.3 then true when r1 <= 0.6 then false else null end, (trunc(random()*10 + 1)), case when r1 <= 0.30001 then 'TAUREAU' when r1 <= 0.60001 then 'LICORNE' else 'DRAGON' end, case when r1 <= 0.30002 then true when r1 <= 0.60002 then false else null end from serie; INSERT 0 10000000 \d+ Liste des relations Schéma | Nom | Type | Propriétaire | Taille | Description --------+----------------+----------+--------------+------------+------------- public | geants | table | postgres | 1116 MB | public | geants_idg_seq | séquence | postgres | 8192 bytes | (2 lignes) \di+ Liste des relations Schéma | Nom | Type | Propriétaire | Table | Taille | Description --------+-------------+-------+--------------+--------+--------+------------- public | geants_pkey | index | postgres | geants | 214 MB | (1 ligne) explain select devise from geants where idg = 1300720; QUERY PLAN --------------------------------------------------------------------------- Index Scan using geants_pkey on geants (cost=0.43..8.45 rows=1 width=33) Index Cond: (idg = 1300720) (2 lignes)

La requête testée est efficace puisqu’elle entraîne un accès à la table après un test d’égalité sur la clé primaire. Elle correspond aux critères fixés par la documentation PostgreSQL pour utiliser un plan générique. 100000 exécutions de cette requête seront effectuées via différentes instructions en php. Il s’agit d’exemples théoriques, la meilleure méthode pour ramener 100000 lignes en connaissant 100000 identifiants ne serait de toute façon pas d'effectuer 100000 requêtes !

1ère démonstration :

Code php :


<?php
$time = microtime();
$time = explode(' ', $time);
$time = $time[1] + $time[0];
$start = $time;

try {
   $dbconn=new PDO('pgsql:host=xxxx;port=xxxx;dbname=xxxx;user=xxxx;password=xxxx');   
} catch (PDOException $e) {
    echo '&eacute;chec lors de la connexion : ' . $e->getMessage();
}

echo '<table>';    
   for ($i = 1; ; $i++) {
    if ($i > 100000) {
        break;
    }
    $idg = rand(1, 10000000);    
    $row = $dbconn->query("select devise from geants where idg = $idg")->fetch(PDO::FETCH_OBJ);
    echo '<tr>';
    echo '<td>';
    echo $idg;
    echo '</td>';
    echo '<td>';
    echo $row->devise;
    echo '</td>';
    echo '</tr>';
}

echo '</table>';
$time = microtime();
$time = explode(' ', $time);
$time = $time[1] + $time[0];
$finish = $time;
$total_time = round(($finish - $start), 4);
echo 'Page generated in '.$total_time.' seconds.';
?>

Affichage au niveau du navigateur : -- execution 1 Page generated in 95.4891 seconds. -- execution 2 Page generated in 95.0339 seconds. -- execution 3 Page generated in 95.0329 seconds. Extrait du log postgresql : ... 2018-01-08 18:11:48.641 CET [3299] postgres@postgres LOG: instruction : DEALLOCATE pdo_stmt_00001e13 2018-01-08 18:11:48.642 CET [3299] postgres@postgres LOG: exécute pdo_stmt_00001e14: select devise from geants where idg = 3777599 2018-01-08 18:11:48.642 CET [3299] postgres@postgres LOG: instruction : DEALLOCATE pdo_stmt_00001e14 2018-01-08 18:11:48.643 CET [3299] postgres@postgres LOG: exécute pdo_stmt_00001e15: select devise from geants where idg = 1340214 2018-01-08 18:11:48.643 CET [3299] postgres@postgres LOG: instruction : DEALLOCATE pdo_stmt_00001e15 2018-01-08 18:11:48.644 CET [3299] postgres@postgres LOG: exécute pdo_stmt_00001e16: select devise from geants where idg = 8187284 2018-01-08 18:11:48.644 CET [3299] postgres@postgres LOG: instruction : DEALLOCATE pdo_stmt_00001e16 2018-01-08 18:11:48.645 CET [3299] postgres@postgres LOG: exécute pdo_stmt_00001e17: select devise from geants where idg = 1300720 2018-01-08 18:11:48.645 CET [3299] postgres@postgres LOG: instruction : DEALLOCATE pdo_stmt_00001e17 ... Execution du traqueur pendant quelques secondes au cours de la génération d'une page : time ./t -s 1 -o "case when tquery like 'deallocate%' then 'deallocate' else tquery end , wait_event" -n traqueur 2.03.00 - outil de diagnostic performance pour PostgreSQL 9.3 => 11 INFORMATION, pas d'options de connexions indiquees, utilisation de la base traqueur detectee ... INFORMATION, connecte a la base traqueur INFORMATION, version de PostgreSQL detectee : 100001 INFORMATION, preparation de la collecte ... INFORMATION, execution de la collecte et presentation des resultats ... busy_pc | distinct_exe | tquery | wait_event ---------+--------------+-----------------------------------------+--------------- 33 | 163 / 163 | select devise from geants where idg = 0 | 9 | 43 / 43 | deallocate | 1 | 6 / 6 | select devise from geants where idg = 0 | DataFileRead 0 | 1 / 1 | select devise from geants where idg = 0 | DataFileWrite (4 lignes) real 0m6,519s user 0m0,564s sys 0m0,312s

L’affichage de la page prend un peu plus d’1 minute 35 secondes. Le log permet de constater que chaque requête fait l’objet d’une désaffectation et donc d’une préparation spécifique. Nous n’économisons pas les temps de parse et planification et nous passons un temps non négligeable (9% d’après le traqueur) à faire des DEALLOCATE côté serveur.

2ème démonstration :

Code php :


<?php

$time = microtime();
$time = explode(' ', $time);
$time = $time[1] + $time[0];
$start = $time;

try {
   $dbconn=new PDO('pgsql:host=xxxx;port=xxxx;dbname=xxxx;user=xxxx;password=xxxx');
   $dbconn->setAttribute(PDO::ATTR_EMULATE_PREPARES, true);
} catch (PDOException $e) {
    echo '&eacute;chec lors de la connexion : ' . $e->getMessage();
}

echo '<table>';
    
   for ($i = 1; ; $i++) {
    if ($i > 100000) {
        break;
    }
    $idg = rand(1, 10000000);
    $row = $dbconn->query("select devise from geants where idg = $idg")->fetch(PDO::FETCH_OBJ);
    echo '<tr>';
    echo '<td>';
    echo $idg;
    echo '</td>';
    echo '<td>';
    echo $row->devise;
    echo '</td>';
    echo '</tr>';
}

echo '</table>';

$time = microtime();
$time = explode(' ', $time);
$time = $time[1] + $time[0];
$finish = $time;
$total_time = round(($finish - $start), 4);
echo 'Page generated in '.$total_time.' seconds.';
?>

Affichage au niveau du navigateur : -- execution 1 Page generated in 46.556 seconds. -- execution 2 Page generated in 46.3047 seconds. -- execution 3 Page generated in 46.6605 seconds. Extrait du log postgresql : ... 2018-01-08 18:17:37.258 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 7229967 2018-01-08 18:17:37.258 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 5349236 2018-01-08 18:17:37.259 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 8656 2018-01-08 18:17:37.259 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 1360955 2018-01-08 18:17:37.260 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 6923286 2018-01-08 18:17:37.260 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 5724040 2018-01-08 18:17:37.261 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 2630658 2018-01-08 18:17:37.261 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 2683087 2018-01-08 18:17:37.262 CET [3326] postgres@postgres LOG: instruction : select devise from geants where idg = 5367604 ... Execution du traqueur pendant quelques secondes au cours de la génération d'une page : time ./t -s 1 -o "tquery, wait_event" -n traqueur 2.03.00 - outil de diagnostic performance pour PostgreSQL 9.3 => 11 INFORMATION, pas d'options de connexions indiquees, utilisation de la base traqueur detectee ... INFORMATION, connecte a la base traqueur INFORMATION, version de PostgreSQL detectee : 100001 INFORMATION, preparation de la collecte ... INFORMATION, execution de la collecte et presentation des resultats ... busy_pc | distinct_exe | tquery | wait_event ---------+--------------+-----------------------------------------+--------------- 50 | 247 / 248 | select devise from geants where idg = 0 | 4 | 19 / 19 | select devise from geants where idg = 0 | DataFileRead 3 | 13 / 13 | select devise from geants where idg = 0 | DataFileWrite (3 lignes) real 0m6,493s user 0m0,524s sys 0m0,356s

Le temps tombe à moins de 47s. Ce gain correspond aux PREPARE / DEALLOCATE d’instructions qui ne sont plus effectués par PostgreSQL. PDO::ATTR_EMULATE_PREPARES désactive la préparation native des instructions pour l’émuler en php.

3ème démonstration :

Code php :


<?php


$time = microtime();
$time = explode(' ', $time);
$time = $time[1] + $time[0];
$start = $time;


echo '<table>';

try {
   $dbconn=new PDO('pgsql:host=xxxx;port=xxxx;dbname=xxxx;user=xxxx;password=xxxx');
} catch (PDOException $e) {
    echo '&eacute;chec lors de la connexion : ' . $e->getMessage();
}
    

   $sel = "select devise from geants where idg = :idg";
   $prepreq = $dbconn->prepare($sel);

   for ($i = 1; ; $i++) {
    if ($i > 100000) {
        break;
    }
    $idg = rand(1, 10000000);
    $prepreq->bindParam(':idg', $idg, PDO::PARAM_INT);
    $prepreq->execute();
    $lig = $prepreq->fetch();
    echo '<tr>';
    echo '<td>';
    echo $idg;
    echo '</td>';
    echo '<td>';
    echo $lig[0];
    echo '</td>';
    echo '</tr>';
}

echo '</table>';

$time = microtime();
$time = explode(' ', $time);
$time = $time[1] + $time[0];
$finish = $time;
$total_time = round(($finish - $start), 4);
echo 'Page generated in '.$total_time.' seconds.';
?>

Affichage au niveau du navigateur : -- execution 1 Page generated in 37.9867 seconds. -- execution 2 Page generated in 38.0312 seconds. -- execution 3 Page generated in 38.1946 seconds. Extrait du log postgresql : ... 2018-01-09 15:58:10.903 CET [10165] postgres@postgres LOG: exécute pdo_stmt_00000001: select devise from geants where idg = $1 2018-01-09 15:58:10.903 CET [10165] postgres@postgres DéTAIL: paramètres : $1 = '6985406' 2018-01-09 15:58:10.903 CET [10165] postgres@postgres LOG: exécute pdo_stmt_00000001: select devise from geants where idg = $1 2018-01-09 15:58:10.903 CET [10165] postgres@postgres DéTAIL: paramètres : $1 = '2447939' 2018-01-09 15:58:10.904 CET [10165] postgres@postgres LOG: exécute pdo_stmt_00000001: select devise from geants where idg = $1 2018-01-09 15:58:10.904 CET [10165] postgres@postgres DéTAIL: paramètres : $1 = '9494968' 2018-01-09 15:58:10.904 CET [10165] postgres@postgres LOG: exécute pdo_stmt_00000001: select devise from geants where idg = $1 2018-01-09 15:58:10.904 CET [10165] postgres@postgres DéTAIL: paramètres : $1 = '2957182' 2018-01-09 15:58:10.904 CET [10165] postgres@postgres LOG: exécute pdo_stmt_00000001: select devise from geants where idg = $1 ... Execution du traqueur pendant quelques secondes au cours de la génération d'une page : time ./t -s 1 -o "query , wait_event" traqueur 2.03.00 - outil de diagnostic performance pour PostgreSQL 9.3 => 11 INFORMATION, pas d'options de connexions indiquees, utilisation de la base traqueur detectee ... INFORMATION, connecte a la base traqueur INFORMATION, version de PostgreSQL detectee : 100001 INFORMATION, preparation de la collecte ... INFORMATION, execution de la collecte et presentation des resultats ... busy_pc | distinct_exe | query | wait_event ---------+--------------+------------------------------------------+--------------- 51 | 256 / 256 | select devise from geants where idg = $1 | 4 | 22 / 22 | select devise from geants where idg = $1 | DataFileRead 2 | 10 / 10 | select devise from geants where idg = $1 | DataFileWrite 0 | 1 / 1 | select devise from geants where idg = $1 | ClientRead (4 lignes) real 0m6,453s user 0m0,568s sys 0m0,328s

38 secondes pour l’affichage des pages. Une seule préparation est effectuée pour les 100 000 exécutions. Les instructions préparées par PostgreSQL prennent leur revanche sur le cas très défavorable présenté initialement.

Conclusion

      Les exemples sont basiques mais illustrent quelques points de bon sens.
      Si de multiples exécutions de requêtes identiques aux variables près sont effectuées et que ces exécutions sont très efficaces alors le temps passé à parser les requêtes peut devenir non négligeable par rapport aux temps d’exécution. Dans ce cas, préparer les requêtes peut être bénéfique au niveau des performances, dans notre exemple 38s contre 47s.
      Le temps de préparation et de désaffectation d’une instruction n’est cependant pas nul. Si les requêtes sont efficaces à l’exécution et que chaque instruction préparée n’est exécutée qu’une fois alors faire préparer les instructions par PostgreSQL a un impact négatif sur les performances, dans notre exemple 95s contre 47s.

Instructions préparées - partie 1

Mise à jour : 11/01/2018