Forums PostgreSQL.fr

ruizsebastien

Membre

PgBadger et fonctions

Bonjour,

Nous utilisons PgBadger (qui fonctionne très bien) mais nous aimerions savoir s'il est possible d'avoir le détail de l'exécution d'une fonction (toutes les requêtes qui sont exécutées par cette fonction). Car par défaut, PgBadger se contente d'afficher seulement la durée de la fonction entière mais pas le détail.

---

Cordialement,

Sébastien.

rjuju

Administrateur

Re : PgBadger et fonctions

Bonjour,

ce n'est hélas pas possible. PgBadger se base sur les logs, et ceux-ci ne remontent pas le détail des requêtes d'une procédure stockée.

De plus, les procédures stockées ne font pas que lancer des requêtes, il y a tout le code applicatif, plpgsql, perl ou autre ...

---

Julien.
https://rjuju.github.io/

ruizsebastien

Membre

Re : PgBadger et fonctions

Bonjour,

En fait si on peut avoir les logs du détails des fonctions avec les paramètres adéquats dans postgresql.conf mais du coup ce n'est pas compatible avec pgbadger...

Peut être dans une prochaine version de pgbadger ?

---

Cordialement,

Sébastien.

gleu

Administrateur

Re : PgBadger et fonctions

J'aimerais bien savoir de quels paramètres vous parlez parce qu'à ma connaissance ça n'existe pas (à moins d'installer un module supplémentaire qui le ferait, mais je n'ai pas non plus connaissance d'un tel module, sauf peut-être auto_explain).

---

Guillaume.

ruizsebastien

Membre

Re : PgBadger et fonctions

Voici ce que nous avons dans un de nos cluster :

log_filename = 'postgresql-%Y%m%d-%Hheure.log'
logging_collector = on
log_truncate_on_rotation = off
log_directory = '/P0K2YY51_B/pg_log'
log_error_verbosity = terse
log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d '
#log_min_duration_statement = '2s'
#pour parametre log_statement : commentaire a remettre pour pgbadger
log_statement = all

log_rotation_age = 60

#parametres pour pg_stat_statements
#shared_preload_libraries=> chargement de 2 librairies
shared_preload_libraries = 'pg_stat_statements, auto_explain'
custom_variable_classes = 'pg_stat_statements, auto_explain'
pg_stat_statements.max = 10000
pg_stat_statements.track = all
#trace activite
track_functions = pl
#parametres explain plan
auto_explain.log_min_duration = '3s'
auto_explain.log_nested_statements=on

log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d'
log_min_duration_statement = 0
log_checkpoints = on
log_connections = on
log_disconnections = on
log_lock_waits = on
log_temp_files = 0
lc_messages='C'

Et voici à titre d'exemple ce que nous avons dans nos logs :
2013-01-10 16:16:05 CET [1234]: [22-1] user=mcod,db=choregie_dbLOG:  temporary file: path "pg_tblspc/16385/PG_9.1_201105231/pgsql_tmp/pgsql_tmp1234.10", size 58129812
2013-01-10 16:16:05 CET [1234]: [23-1] user=mcod,db=choregie_dbSTATEMENT:  INSERT INTO cot_justif (
        idejuscalcot, ideelecot, val, utl, usg, lib)
        SELECT nextval('cot_idejuscalcot_justifcalcot_seq'), m.idesq, j.val, j.utl,
        j.usg, j.lib
        FROM JUSTIFICATIF_TRV j
        INNER JOIN MAPPINGCOT_TRV m ON m.ide=j.ideelecot limit 50000000
2013-01-10 16:16:23 CET [1234]: [24-1] user=mcod,db=choregie_dbLOG:  duration: 2111611.243 ms  plan:
        Query Text: INSERT INTO cot_justif (
        idejuscalcot, ideelecot, val, utl, usg, lib)
        SELECT nextval('cot_idejuscalcot_justifcalcot_seq'), m.idesq, j.val, j.utl,
        j.usg, j.lib
        FROM JUSTIFICATIF_TRV j
        INNER JOIN MAPPINGCOT_TRV m ON m.ide=j.ideelecot limit 50000000
        Insert on cot_justif  (cost=846419.11..5926987.55 rows=50000000 width=40)
          ->  Subquery Scan on "*SELECT*"  (cost=846419.11..5926987.55 rows=50000000 width=40)
                ->  Limit  (cost=846419.11..4926987.55 rows=50000000 width=32)
                      ->  Hash Join  (cost=846419.11..60353475.35 rows=729151552 width=32)
                            Hash Cond: (j.ideelecot = m.ide)
                            ->  Seq Scan on justificatif_trv j  (cost=0.00..14777438.52 rows=729151552 width=32)
                            ->  Hash  (cost=397686.16..397686.16 rows=25814716 width=16)
                                  Buckets: 262144  Batches: 16  Memory Usage: 75690kB
                                  ->  Seq Scan on mappingcot_trv m  (cost=0.00..397686.16 rows=25814716 width=16)

---

Cordialement,

Sébastien.

gleu

Administrateur

Re : PgBadger et fonctions

Donc c'est bien autoexplain, donc vous ne tracez pas toutes les requêtes des procédures stockées, mais seulement celles de plus de 3 secondes.

Quant à ajouter la récupération des traces d'autoexplain, Gilles y était fortement opposé. Le problème que j'y vois est que vous risquez de compter deux fois les mêmes requêtes, une fois pour leur trace avec log_min_duration_statement et une fois pour leur trace avec auto_explain. Et on n'a pas trouvé de moyen de contourner ça.

---

Guillaume.

ruizsebastien

Membre

Re : PgBadger et fonctions

c'est dommage parce que du coup on doit se passer de pgbadger pour faire du tuning sur les requêtes de nos fonctions.

Beau travail quand même sur pgbadger.

---

Cordialement,

Sébastien.

gleu

Administrateur

Re : PgBadger et fonctions

Vous pouvez toujours faire une demande sur github (https://github.com/dalibo/pgbadger). Gilles vous répondra directement. Après tout, peut-être que ça l'intéressera et qu'il trouvera une bonne solution.

---

Guillaume.

ruizsebastien

Membre

Re : PgBadger et fonctions

Merci.

C'est fait.

---

Cordialement,

Sébastien.