Vous n'êtes pas identifié(e).
Bonjour
Nous avons dû passer dans l'urgence notre production de la version 11 à la 15 et nous avons un environnement de test en 14.
Certaines de nos requêtes sont très lentes (200 ms en pg 11 contre 17s en PG15 et 12s en PG 14) alors que la production est virtualisée et à pas mal de ressource
je voudrais vous envoyer les 2 plans d’exécution pour une requête exemple mais je ne vois pas où ajouter des pj au message
truc bizarre dans cette requête exemple si je fais
select a.* from t1 a left join t2 b on b.nip=a.nip where (select count(z.*)>0 from t3 z where z.nip=a.nip) c'est lent
select a.* from t1 a left join t2 b on b.nip=a.nip where (select count(z.*)>0 from t3 z where z.nip=a.nip and z.nip=b.nip) c'est rapide
alors qu'on voit dans le left join que a.nip = b.nip
En avance merci pour votre aide
Bon dimanche
Dernière modification par dev.isc84 (29/05/2023 08:44:45)
Hors ligne
Bonjour,
Comment avez-vous fait la migration vers pg15? En cas de pg_upgrade, avez-vous effectué les différentes commandes générées par pg_upgrade, cf https://www.postgresql.org/docs/current/pgupgrade.html étapes 14 et 15 ?
Julien.
https://rjuju.github.io/
Hors ligne
Bonjour
Nous avions créer un nouveau serveur en 15 tout en ayant notre production toujours sur la 11 le temps de faire les tests.
Nous avions fait le changement de nos tables with oids sur la 11 car cela ne marche plus avec la PG 15.
Nous avons fait un backup de la 11 puis un restore sur ce nouveau serveur postgres 15
Il n'y a pas eu d'erreur dans le restore
Nous avons fait ensuite un vaccuum full analyze sur la 15
Dernière modification par dev.isc84 (29/05/2023 08:49:20)
Hors ligne
Un VACUUM FULL après un pg_restore n'est pas nécessaire. Je crois cependant qu'un VACUUM FULL ANALYZE ne revient pas au même qu'un VACUUM FULL suivi d'un ANALYZE. Pouvez-vous essayer d'effectuer un ANALYZE sur toutes vos bases et voir si cela corrige le problème ?
Julien.
https://rjuju.github.io/
Hors ligne
Bonjour
Merci Julien pour votre réponse
Malheureusement non le Vaccum sur toute la base ne change rien sur le temps de l’exécution de la requête d'exemple
autre exemple mais on dirait que c'est le même type de probleme:
(select sum(nb)::integer as nb from vue_onco_observations_validations_nb_secretaires1 where secretaire in ('DIDIER'))
union all
(select count(a.*) as nb from dsi.dsi_examen_clinique a inner join adm_pat b on b.nip = a.nip inner join prog_utilisateur c on c.code = a.agent where a.type =3
and (select count(z.*)=0 from onco_ooo z inner join onco_courrier_archive y on y.nip=z.nip
and y.idsarchive like '%¤'||z.id||'¤%' where
--z.nip = b.nip and
z.nip=a.nip and z.visible and z.date=a.date_creation::date)
and a.visible and a.date_validation is not null and c.code in ('DIDIER'))
si on joue seul la 1ere requête avant l'union c'est rapide 150ms si on joue seule celle après l'union c'est aussi rapide 200ms si on joue toute la requête c'est lent 3 secondes
si je rajoute ce qui est commenté ci dessus z.nip=b.nip c'est rapide, alors qu'il y avait z.nip=a.nip et a.nip=b.nip
si je fais un explain analyze sur la requête lente la lenteur vient d'un seq scan sur adm_pat.nip (alors qu'il y a un index sur nip) la table adm_pat a 150000 lignes
si je fais un explain analyze sur la requête rapide j'ai aussi le seq scan sur adm_pat avec les mêmes infos mais c'est rapide
Bonne journée
Didier
Dernière modification par dev.isc84 (30/05/2023 09:10:55)
Hors ligne
Avez-vous effectué un VACUUM ou un ANALYZE ? Je parlais bien d'un ANALYZE (voire VACUUM ANALYZE, mais pas VACUUM seul ni VACUUM FULL).
Pouvez-vous montrer le résultat d'un EXPLAIN (ANALYZE, BUFFERS) sur une requête rapide avec l'ancien derveur et lente avec le nouveau ?
Julien.
https://rjuju.github.io/
Hors ligne
j'ai bien fait un analyze et aussi un vacuum voici l'explain analyze buffers de la lente de la requête ci dessus sur une PG14
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Append (cost=490189.62..850871.57 rows=2 width=8) (actual time=3161.806..3170.172 rows=2 loops=1)
Buffers: shared hit=172266, temp read=483 written=483
-> Subquery Scan on "*SELECT* 1" (cost=490189.62..490189.65 rows=1 width=8) (actual time=3161.803..3161.827 rows=1 loops=1)
Buffers: shared hit=170969, temp read=483 written=483
-> Aggregate (cost=490189.62..490189.64 rows=1 width=4) (actual time=3161.801..3161.823 rows=1 loops=1)
Buffers: shared hit=170969, temp read=483 written=483
-> GroupAggregate (cost=458940.36..490187.12 rows=200 width=40) (actual time=3161.792..3161.814 rows=0 loops=1)
Group Key: vue_onco_observations_validations_secretaires.secretaire
Buffers: shared hit=170969, temp read=483 written=483
-> Subquery Scan on vue_onco_observations_validations_secretaires (cost=458940.36..490174.71 rows=2082 width=40) (actual time=3161.790..3161.811 rows=0 loops=1)
Filter: (vue_onco_observations_validations_secretaires.secretaire = 'DIDIER'::text)
Rows Removed by Filter: 3391
Buffers: shared hit=170969, temp read=483 written=483
-> Unique (cost=458940.36..484968.99 rows=416458 width=435) (actual time=3158.944..3161.518 rows=3391 loops=1)
Buffers: shared hit=170969, temp read=483 written=483
-> Sort (cost=458940.36..459981.51 rows=416458 width=435) (actual time=3158.938..3159.427 rows=6155 loops=1)
Sort Key: a_1.id, a_1.medecin, a_1.jword_document, (((CASE WHEN ((d.prenom IS NULL) OR (char_length((d.prenom)::text) < 1)) THEN initcap((d.nom)::text) ELSE ((initcap((d.nom)::text) || ' '::text) || initcap((d.prenom)::text)) END || ' - '::text) || (d.nip)::text)), a_1.courrier_cree, a_1.date, ((CASE WHEN ((a_1.mise_en_forme_demandee IS NOT NULL) AND (a_1.mise_en_forme_effectuee IS NULL) AND (e.code IS NOT NULL)) THEN (e.code)::character varying ELSE (a_1.secretaire)::character varying END)::text), a_1.nip, a_1.type, a_1.attente_validation_date, a_1.attente_validation_login, a_1.correction_demandee_date, a_1.correction_demandee_login, a_1.correction_effectuee_date, a_1.correction_effectuee_login, a_1.mise_en_forme_effectuee, a_1.mise_en_forme_demandee, a_1.validation_date, a_1.validation_login, a_1.correction_demandee, ((CASE WHEN ((b.prenom IS NULL) OR (char_length((b.prenom)::text) < 1)) THEN initcap((b.nom)::text) ELSE (((initcap((b.nom)::text) || ' '::text) || upper(SUBSTRING(b.prenom FROM 1 FOR 1))) || '.'::text) END)::character varying), ((CASE WHEN ((c.prenom IS NULL) OR (char_length((c.prenom)::text) < 1)) THEN initcap((c.nom)::text) ELSE (((initcap((c.nom)::text) || ' '::text) || upper(SUBSTRING(c.prenom FROM 1 FOR 1))) || '.'::text) END)::character varying), b.code, (NULL::text)
Sort Method: quicksort Memory: 1831kB
Buffers: shared hit=170969, temp read=483 written=483
-> Merge Right Join (cost=281576.56..318635.86 rows=416458 width=435) (actual time=3135.530..3149.809 rows=6155 loops=1)
Merge Cond: (e.code_medecin_dragon = a_1.secretaire)
Buffers: shared hit=170969, temp read=483 written=483
-> Sort (cost=48.35..49.93 rows=634 width=8) (actual time=2868.760..2868.792 rows=338 loops=1)
Sort Key: e.code_medecin_dragon
Sort Method: quicksort Memory: 54kB
Buffers: shared hit=5
-> Seq Scan on onco_reouverture_session_onco e (cost=0.00..18.84 rows=634 width=8) (actual time=2868.514..2868.623 rows=634 loops=1)
Buffers: shared hit=5
-> Materialize (cost=281528.21..282760.33 rows=246425 width=392) (actual time=266.666..268.014 rows=6155 loops=1)
Buffers: shared hit=170964, temp read=483 written=483
-> Sort (cost=281528.21..282144.27 rows=246425 width=392) (actual time=266.660..267.147 rows=3391 loops=1)
Sort Key: a_1.secretaire
Sort Method: quicksort Memory: 999kB
Buffers: shared hit=170964, temp read=483 written=483
-> Hash Join (cost=126478.13..205649.68 rows=246425 width=392) (actual time=241.728..263.982 rows=3391 loops=1)
Hash Cond: (a_1.secretaire = (c.code)::text)
Buffers: shared hit=170964, temp read=483 written=483
-> Hash Join (cost=126358.59..204882.08 rows=246425 width=377) (actual time=240.126..261.595 rows=3391 loops=1)
Hash Cond: (a_1.nip = d.nip)
Buffers: shared hit=168722, temp read=483 written=483
-> Hash Join (cost=96569.74..114388.85 rows=246425 width=354) (actual time=15.013..17.745 rows=3391 loops=1)
Hash Cond: (d0.code_utilisateur = (b.code)::text)
Buffers: shared hit=15371
-> Hash Join (cost=96450.20..113578.12 rows=262853 width=339) (actual time=13.404..15.436 rows=3392 loops=1)
Hash Cond: (a_1.medecin = d0.code)
Buffers: shared hit=13129
-> Unique (cost=96434.69..110234.47 rows=262853 width=332) (actual time=13.217..14.336 rows=3392 loops=1)
Buffers: shared hit=13002
-> Sort (cost=96434.69..97091.82 rows=262853 width=332) (actual time=13.213..13.482 rows=3392 loops=1)
Sort Key: a_1.jword_document, a_1.courrier_cree, a_1.id, a_1.medecin, a_1.date, a_1.secretaire, a_1.nip, a_1.type, a_1.attente_validation_date, a_1.attente_validation_login, a_1.correction_demandee_date, a_1.correction_demandee_login, a_1.correction_effectuee_date, a_1.correction_effectuee_login, a_1.mise_en_forme_effectuee, a_1.mise_en_forme_demandee, a_1.validation_date, a_1.validation_login, a_1.correction_demandee, (NULL::text)
Sort Method: quicksort Memory: 577kB
Buffers: shared hit=13002
-> Append (cost=0.28..23099.20 rows=262853 width=332) (actual time=0.018..10.193 rows=3392 loops=1)
Hors ligne
voici la rapide sur la PG11
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Append (cost=270640.39..272844.85 rows=2 width=8) (actual time=246.826..247.273 rows=2 loops=1)
Buffers: shared hit=16324, temp read=41 written=41
-> Subquery Scan on "*SELECT* 1" (cost=270640.39..270640.42 rows=1 width=8) (actual time=246.825..246.827 rows=1 loops=1)
Buffers: shared hit=16298, temp read=41 written=41
-> Aggregate (cost=270640.39..270640.41 rows=1 width=4) (actual time=246.821..246.822 rows=1 loops=1)
Buffers: shared hit=16298, temp read=41 written=41
-> GroupAggregate (cost=248624.83..270637.89 rows=200 width=40) (actual time=246.810..246.810 rows=0 loops=1)
Group Key: vue_onco_observations_validations_secretaires.secretaire
Buffers: shared hit=16298, temp read=41 written=41
-> Subquery Scan on vue_onco_observations_validations_secretaires (cost=248624.83..270628.56 rows=1467 width=40) (actual time=246.801..246.801 rows=0 loops=1)
Filter: (vue_onco_observations_validations_secretaires.secretaire = 'DIDIER'::text)
Rows Removed by Filter: 2045
Buffers: shared hit=16298, temp read=41 written=41
-> Unique (cost=248624.83..266961.27 rows=293383 width=435) (actual time=243.253..246.305 rows=2045 loops=1)
Buffers: shared hit=16298, temp read=41 written=41
-> Sort (cost=248624.83..249358.29 rows=293383 width=435) (actual time=243.246..243.526 rows=2843 loops=1)
Sort Key: a_1.id, a_1.medecin, a_1.jword_document, ((((CASE WHEN ((d.prenom IS NULL) OR (char_length((d.prenom)::text) < 1)) THEN initcap((d.nom)::text) ELSE ((initcap((d.nom)::text) || ' '::text) || initcap((d.prenom)::text)) END)::text || ' - '::text) || (d.nip)::text)), a_1.courrier_cree, a_1.date, ((CASE WHEN ((a_1.mise_en_forme_demandee IS NOT NULL) AND (a_1.mise_en_forme_effectuee IS NULL) AND (e.code IS NOT NULL)) THEN (e.code)::character varying ELSE (a_1.secretaire)::character varying END)::text), a_1.nip, a_1.type, a_1.attente_validation_date, a_1.attente_validation_login, a_1.correction_demandee_date, a_1.correction_demandee_login, a_1.correction_effectuee_date, a_1.correction_effectuee_login, a_1.mise_en_forme_effectuee, a_1.mise_en_forme_demandee, a_1.validation_date, a_1.validation_login, a_1.correction_demandee, ((CASE WHEN ((b.prenom IS NULL) OR (char_length((b.prenom)::text) < 1)) THEN initcap((b.nom)::text) ELSE (((initcap((b.nom)::text) || ' '::text) || upper("substring"((b.prenom)::text, 1, 1))) || '.'::text) END)::character varying), ((CASE WHEN ((c.prenom IS NULL) OR (char_length((c.prenom)::text) < 1)) THEN initcap((c.nom)::text) ELSE (((initcap((c.nom)::text) || ' '::text) || upper("substring"((c.prenom)::text, 1, 1))) || '.'::text) END)::character varying), b.code, (NULL::text)
Sort Method: quicksort Memory: 854kB
Buffers: shared hit=16298, temp read=41 written=41
-> Hash Join (cost=121607.03..172128.10 rows=293383 width=435) (actual time=209.119..234.526 rows=2843 loops=1)
Hash Cond: (a_1.nip = d.nip)
Buffers: shared hit=16298, temp read=41 written=41
-> Hash Join (cost=103259.74..131740.39 rows=293383 width=376) (actual time=28.865..38.141 rows=2843 loops=1)
Hash Cond: (a_1.secretaire = (c.code)::text)
Buffers: shared hit=1333, temp read=41 written=41
-> Hash Right Join (cost=103175.72..130884.65 rows=293383 width=361) (actual time=27.133..34.125 rows=2843 loops=1)
Hash Cond: (e.code_medecin_dragon = a_1.secretaire)
Buffers: shared hit=1295, temp read=41 written=41
-> Seq Scan on onco_reouverture_session_onco e (cost=0.00..9.60 rows=560 width=8) (actual time=0.032..0.196 rows=560 loops=1)
Buffers: shared hit=4
-> Hash (cost=90597.86..90597.86 rows=211829 width=354) (actual time=26.334..26.334 rows=2045 loops=1)
Buckets: 65536 Batches: 8 Memory Usage: 535kB
Buffers: shared hit=1291, temp written=29
-> Hash Join (cost=75219.02..90597.86 rows=211829 width=354) (actual time=19.616..23.755 rows=2045 loops=1)
Hash Cond: (d0.code_utilisateur = (b.code)::text)
Buffers: shared hit=1291
-> Hash Join (cost=75135.00..89917.24 rows=226840 width=339) (actual time=18.273..21.230 rows=2046 loops=1)
Hash Cond: (a_1.medecin = d0.code)
Buffers: shared hit=1253
-> Unique (cost=75124.88..87033.98 rows=226840 width=332) (actual time=17.993..19.336 rows=2046 loops=1)
Buffers: shared hit=1249
-> Sort (cost=75124.88..75691.98 rows=226840 width=332) (actual time=17.985..18.205 rows=2046 loops=1)
Sort Key: a_1.jword_document, a_1.courrier_cree, a_1.id, a_1.medecin, a_1.date, a_1.secretaire, a_1.nip, a_1.type, a_1.attente_validation_date, a_1.attente_validation_login, a_1.correction_demandee_date, a_1.correction_demandee_login, a_1.correction_effectuee_date, a_1.correction_effectuee_login, a_1.mise_en_forme_effectuee, a_1.mise_en_forme_demandee, a_1.validation_date, a_1.validation_login, a_1.correction_demandee, (NULL::text)
Sort Method: quicksort Memory: 338kB
Buffers: shared hit=1249
-> Append (cost=102.94..25038.97 rows=226840 width=332) (actual time=0.730..14.467 rows=2046 loops=1)
Buffers: shared hit=1249
-> Bitmap Heap Scan on onco_ooo_observations a_1 (cost=102.94..17442.16 rows=215622 width=184) (actual time=0.722..6.667 rows=1952 loops=1)
Recheck Cond: (visible AND (courrier_cree IS NOT TRUE) AND ((validation_login IS NOT NULL) OR ((correction_demandee IS NOT NULL) AND (correction_effectuee_date IS NULL)) OR ((mise_en_forme_demandee IS NOT NULL) AND (mise_en_forme_effectuee IS NULL))))
Heap Blocks: exact=980
Buffers: shared hit=992
-> Bitmap Index Scan on index_onco_ooo_observations_validations4 (cost=0.00..49.04 rows=215622 width=0) (actual time=0.500..0.500 rows=1952 loops=1)
Buffers: shared hit=12
-> Bitmap Heap Scan on onco_ooo_observations_sejours a_1_1 (cost=8.95..3861.24 rows=9629 width=187) (actual time=0.053..0.370 rows=80 loops=1)
Recheck Cond: (visible AND (courrier_cree IS NOT TRUE) AND (fin IS TRUE) AND ((validation_login IS NOT NULL) OR ((correction_demandee IS NOT NULL) AND (correction_effectuee_date IS NULL)) OR ((mise_en_forme_demandee IS NOT NULL) AND (mise_en_forme_effectuee IS NULL))))
Heap Blocks: exact=57
Buffers: shared hit=58
-> Bitmap Index Scan on index_onco_ooo_observations_validations5 (cost=0.00..6.54 rows=9629 width=0) (actual time=0.026..0.026 rows=80 loops=1)
Buffers: shared hit=1
-> Seq Scan on onco_ooo_observations_oncogenetique a_1_2 (cost=0.00..332.97 rows=1589 width=230) (actual time=6.266..7.118 rows=14 loops=1)
Filter: (visible AND (courrier_cree IS NOT TRUE) AND ((validation_login IS NOT NULL) OR ((correction_demandee IS NOT NULL) AND (correction_effectuee_date IS NULL)) OR ((mise_en_forme_demandee IS NOT NULL) AND (mise_en_forme_effectuee IS NULL)) OR ((secretaire2 IS NOT NULL) AND (validation_secretaire_2 IS NULL))))
Rows Removed by Filter: 13383
Buffers: shared hit=199
-> Hash (cost=6.72..6.72 rows=272 width=12) (actual time=0.209..0.209 rows=272 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 20kB
Buffers: shared hit=4
-> Seq Scan on onco_auteur d0 (cost=0.00..6.72 rows=272 width=12) (actual time=0.025..0.110 rows=272 loops=1)
Buffers: shared hit=4
-> Hash (cost=58.45..58.45 rows=2045 width=22) (actual time=1.296..1.296 rows=2045 loops=1)
Buckets: 2048 Batches: 1 Memory Usage: 127kB
Buffers: shared hit=38
-> Seq Scan on prog_utilisateur b (cost=0.00..58.45 rows=2045 width=22) (actual time=0.012..0.576 rows=2045 loops=1)
Buffers: shared hit=38
:
Hors ligne
Nous avons trouvé c'était seulement JIT qui était consommateur de ressource.
Cela prenait 3.8 secondes sur 4 secondes d’exécution
Donc sans JIT ça prends 200ms c'est même un peu mieux que la PG 11.
JIT était désactivé sous notre PG 11 mais activé par défaut sur la PG 15...
Hors ligne
Bien vu ! merci d'avoir partagé ce cas concret, c'est très intéressant.
Cordialement,
Sébastien.
Hors ligne
