Programme bloqué ?

Message par **Phil** » mer. 9 déc. 2020 18:33

Merci à Julien pour sa question

"Mon programme semble bloqué depuis 5h27 ce matin, peux-tu analyser ?"

Si la requête était terminée, il faudrait analyser les données collectées par le traqueur en mode batch mais, ici, le problème est toujours en cours donc exécution du traqueur en interactif :

Code : Tout sélectionner

/opt/traqueur/11/t
traqueur 4.02.02 - https://pgphil.ovh - outil de diagnostic performance pour PostgreSQL 9.5 => 13
INFORMATION, pas de base de connexion indiquee, utilisation de la base dediee detectee ...
INFORMATION, connecte a la base traqueur
INFORMATION, version de PostgreSQL detectee : 110007
INFORMATION, preparation de la collecte ...
INFORMATION, execution de la collecte et presentation des resultats ...
busy_pc | distinct_exe |  db   |  pid   | pg_user |   client_ip   |      application       |                              query                               | wait_event_type | blockers
---------+--------------+-------+--------+---------+---------------+------------------------+------------------------------------------------------------------+-----------------+----------
    100 | 1 / 50       | xxxxx | 112614 | xxxxx   | xx.xxx.xx.xxx | PostgreSQL JDBC Driver | INSERT INTO T1 ( ............................................... |                 |

wait_event_type à NULL , pas de LOCK ou d'I/O, on est sur le CPU donc a priori problème de plan d’exécution.

Nouvelle exécution du traqueur pour avoir l'heure précise de début de la requête ainsi que son code SQL complet.

Code : Tout sélectionner

/opt/traqueur/11/t -o "query_start, query"

Début de la requête : 2020-12-09 05:27:13.482062+01
La requête est en fait un INSERT ... SELECT

Ce n’est pas l’INSERT qui pose problème mais la partie SELECT. Un explain analyze de ce SELECT répond rapidement (2s4) :

Code : Tout sélectionner

                                                                        QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------------------------
...
Planning Time: 0.591 ms
Execution Time: 2391.416 ms

Si le planner trouve actuellement le bon plan, les informations ou les conditions dont il dispose sont différentes entre les 2 exécutions. Cela peut être le positionnement erroné de paramètres comme enable_* ou encore un problème de stats au moment du début de la requête. La requête implique 3 tables, t1, t2 et t3. t1 est une table (relativement) petite par rapport à t2 et t3.

Code : Tout sélectionner

select relname,last_vacuum, last_autovacuum, last_analyze, last_autoanalyze from pg_stat_user_tables where relname in ('t1', 't2', t3');
    relname    |          last_vacuum          |        last_autovacuum        |         last_analyze          |       last_autoanalyze
---------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------
t1             | 2020-12-08 04:33:31.339144+01 | 2020-12-08 04:35:40.996863+01 | 2020-12-08 04:33:31.411906+01 | 2020-12-09 05:27:51.90026+01
t2             | 2020-12-09 05:27:07.037609+01 | 2020-12-09 10:43:36.734117+01 | 2020-12-09 05:27:08.057124+01 | 2020-12-09 05:20:59.706715+01
t3             | 2020-12-09 05:27:08.646903+01 | 2020-12-09 10:43:06.483768+01 | 2020-12-09 05:27:09.477858+01 | 2020-12-08 07:53:43.262202+01

Les tables t2 et t3 sont bien analysées manuellement dans le programme d’alimentation juste AVANT la requête. Le hic est sur t1.
Le dernier analyze de T1 a eu lieu le 08/12 à 4h33. Le dernier autoanalyze de t1 a eu lieu le 09/12 à 5h27min51. La requête démarrée le 09/12 à 5h27min13s n’avait pas le bon plan car les stats n'étaient pas pertinentes. Il faut passer les stats après avoir alimenté cette table t1 qui varie en taille d’un jour sur l’autre.

La solution est de donc de passer un analyze de t1 dans le programme comme pour t2 et t3 avant d'exécuter cette requête. Un batch alimentant une table puis l'utilisant immédiatement ensuite doit idéalement ne pas compter sur autovacuum. Par ailleurs, les "petites" tables ont tout autant besoin d'être analysées que les grosses tables.