Forums PostgreSQL.fr

Christophe-LT

Membre

Lenteur d'execution - PostgreSQL 8.2

Bonjour,
Je viens de récupérer le développement pour un client et je suis confronté à des temps d’exécution extrêmement longs (parfois supérieurs à 100s) pour certaines requêtes.
J'ai très peu d'expérience avec PostgreSQL, je viens donc vous demander conseil.

Tout d'abord voici quelques infos sur le serveur :
- Intel XEON E5620 @ 2.40Ghz - 4 cœurs
- 24 Go de RAM - Disque dur de 2 To

- version PostgreSQL 8.2.20 on x86_64-unknown-linux-gnu, compiled by GCC gcc (Debian 4.3.2-1.1) 4.3.2
- autovacuum off
- client_encoding latin1
- lc_collate en_US.UTF-8
- lc_ctype en_US.UTF-8
- max_connections 200
- max_fsm_pages 153600
- max_stack_depth 2MB
- server_encoding LATIN1
- shared_buffers 24MB
- stats_row_level on
- stats_start_collector on
- TimeZone Europe/Paris

Sur ce serveur tournent 25 bases allant de quelques Mo à plus de 100 Go.
Les bases me posant problèmes font moins de 500 Mo.

Voici un exemple de requête :
SELECT a.*,member_with_pseudo(a.id_user) AS pseudo_name
FROM gagnants a JOIN users b ON b.id=a.id_user JOIN lots c ON a.id_lot=c.id
WHERE 1=1 and nom_cadeau LIKE '%retrait%'
ORDER BY a.date DESC LIMIT 20 offset 0
Cette requête s’exécute en 1.34s ce qui est, me semble t-il, plutôt lent.

Maintenant la même requête en changeant simplement l'offset :
SELECT a.*,member_with_pseudo(a.id_user) AS pseudo_name
FROM gagnants a JOIN users b ON b.id=a.id_user JOIN lots c ON a.id_lot=c.id
WHERE 1=1 and nom_cadeau LIKE '%retrait%'
ORDER BY a.date DESC LIMIT 20 offset 60
Temps d’exécution 82.87s.

Voici le résultat d'un EXPLAIN ANALYSE de cette même requête :

QUERY PLAN

Limit  (cost=17261.28..17261.33 rows=20 width=329) (actual time=85083.418..85083.423 rows=20 loops=1)

  ->  Sort  (cost=17261.13..17261.40 rows=105 width=329) (actual time=85083.405..85083.416 rows=80 loops=1)

        Sort Key: a.date

        ->  Hash Join  (cost=5526.89..17257.61 rows=105 width=329) (actual time=53.056..85021.846 rows=2254 loops=1)

              Hash Cond: ((a.id_user)::text = (b.id)::text)

              ->  Nested Loop  (cost=0.00..11719.30 rows=3 width=329) (actual time=6.148..63693.420 rows=2345 loops=1)

                    Join Filter: ((a.id_lot)::text = (c.id)::text)

                    ->  Seq Scan on gagnants a  (cost=0.00..4798.48 rows=1 width=329) (actual time=0.023..39.525 rows=2348 loops=1)

                          Filter: ((nom_cadeau)::text ~~ '%retrait%'::text)

                    ->  Seq Scan on lots c  (cost=0.00..6913.13 rows=513 width=4) (actual time=0.006..26.812 rows=451 loops=2348)

              ->  Hash  (cost=5358.62..5358.62 rows=13462 width=4) (actual time=44.019..44.019 rows=13761 loops=1)

                    ->  Seq Scan on users b  (cost=0.00..5358.62 rows=13462 width=4) (actual time=0.014..33.138 rows=13761 loops=1)

Total runtime: 85083.955 ms

Je vous avoue que ça me parle très peu.
Plusieurs questions se posent : ces résultats vous semblent-ils normaux? Que puis-je faire pour améliorer au maximum ces temps?
Si besoin je peux fournir toutes informations manquantes.

Je vous remercie d'avance pour toute l'aide que vous pourrez m'apporter.

flo

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

J'ai du mal à bien comprendre la structure des tables  :  la colonne nom_cadeau appartient à la table gagnants? Et une mention des clés primaires, étrangères, et des index pourrait aider (pour voir s'ils ont été définis correctement ou non, car le parcours séquentiel sur la table lots m'étonne)

Ah, et aussi :
quel est le nombre de lignes de chacune des tables,
quel est le nombre total de lignes contenant un nom_cadeau qui contient "retrait"?

L'optimiseur se plante complètement là-dessus (il pense ne ramener qu'une ligne alors qu'il y en a 2348)

Flo

Dernière modification par flo (20/03/2012 15:44:52)

Christophe-LT

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Tout d'abord merci de votre intérêt.

Pour répondre à vos demandes :
- La colonne "nom_cadeau" appartient bien à la table "gagnants".
- Concernant les index, clés primaires et étrangères, je copie-colle ce qui se trouve dans l'onglet "index" de phpPgAdmin :

Table users (~13462 lignes) :
id_unique         CREATE UNIQUE INDEX id_unique ON users USING btree (id)        Clé unique       
id_user_unique         CREATE UNIQUE INDEX id_user_unique ON users USING btree (id)     Clé unique

Table lots (~513 lignes) :
lots_pkey         CREATE UNIQUE INDEX lots_pkey ON lots USING btree (id)         Clé primaire

Table gagnants (~44118 lignes) :
date_idx     CREATE INDEX date_idx ON gagnants USING btree (date)        
etat_idx     CREATE INDEX etat_idx ON gagnants USING btree (etat)        
gagnants_pkey     CREATE UNIQUE INDEX gagnants_pkey ON gagnants USING btree (id)     Clé primaire   
gagnats_id_user     CREATE INDEX gagnats_id_user ON gagnants USING btree (id_user)    
gagnats_idx     CREATE INDEX gagnats_idx ON gagnants USING btree (id)        
id_lot_idx     CREATE INDEX id_lot_idx ON gagnants USING btree (id_lot)

Le nombre total de lignes contenant "retrait" dans la table "gagnants" est de 2349.

Après avoir discuté avec la personne administrant le serveur il n'y a pas eu de vacuum ni reindex ni quoi que ce soit depuis le changement de serveur (soit plus d'un an). Autovacuum, quant à lui, n'a jamais été activé.

Comme vous l'aurez compris je n'y connais pas grand chose en administration de base de données, de plus PostgreSQL est une nouveauté pour moi...
Quoi qu'il en soit je vous remercie une nouvelle fois de toute l'aide que vous pourrez m'apporter.

Dernière modification par Christophe-LT (20/03/2012 16:59:31)

flo

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Bon, tout d'abord il ne me semble pas qu'il manque des index dans les tables.

Après avoir discuté avec la personne administrant le serveur il n'y a pas eu de vacuum ni reindex ni quoi que ce soit depuis le changement de serveur (soit plus d'un an). Autovacuum, quant à lui, n'a jamais été activé.
.

Ah, ça pourrait avoir un lien. notamment à cause de mauvaises statistiques.
http://docs.postgresqlfr.org/9.1/sql-analyze.html
En un an, je suppose que les données ont pas mal évolué?

Comme vous l'aurez compris je n'y connais pas grand chose en administration de base de données, de plus PostgreSQL est une nouveauté pour moi...

Je suis surtout développeur en fait, mais avant de chercher un problème de paramétrage, de système (ce qui sort de mon domaine de compétence, surtout avec le contexte particulier de votre serveur), j'essayais d'éliminer des causes de développement (ce qui est le cas de la grande majorité des problèmes rencontrés).
Après, d'autres personnes vraiment expérimentées en administration vous aideront certainement si ce n'est pas cela.

Ceci dit, si toutes vos petites bases ont des soucis, c'est soit :
qu'une grande partie des développements ont des problèmes − cela arrive − ( je mets dans le développement la structure des données)
soit des problèmes d'administration

ou un peu de chaque...

Dernière modification par flo (20/03/2012 17:27:10)

gleu

Administrateur

Re : Lenteur d'execution - PostgreSQL 8.2

À mon avis, le truc qui gêne beaucoup dans cette requête, c'est cette ligne : Join Filter: ((a.id_lot)::text = (c.id)::text)

Il transforme id_lot de la table gagnants et id de la table lots en text. Vu leur nom, j'aurais tendance à penser que ce sont plutôt des integer. Mais j'ai du mal à croire qu'il force cette conversion sans raison. J'ai peur que id_lot soit de type text (ou varchar ou un équivalent). Pouvez-vous nous donner la définition des tables ? Merci.

Parce que id de la table lots est une clé primaire. Donc même s'il continue à insister de faire un Nested Loop entre gagnants et lots, il devrait au moins faire le parcours de lots en IndexScan. Le fait qu'il le fait en parcours séquentiel, et qu'il doive faire ce parcours plusieurs milliers de fois donne un coup monstrueux au performance. C'est d'ailleurs la partie qui consomme le plus (26  ms * 2348 = 61 secondes, autrement dit les 3/4 de la durée d'exécution de la requête. Ce que montre d'ailleurs bien le site explain (http://explain.depesz.com/s/pDo).

Bref, la définition des tables devrait nous donner des pistes sérieuses.

---

Guillaume.

gleu

Administrateur

Re : Lenteur d'execution - PostgreSQL 8.2

Et maintenant que j'ai fait Envoyer, je me dis que le même problème se pose sur le deuxième nœud gênant, mais entre la table gagnants, colonne id_user et la table users, colonne id. Suis persuadé que lr problème se pose ici aussi.

---

Guillaume.

Christophe-LT

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Effectivement les clés étrangères de la table "gagnants" sont de type VARCHAR.
En parcourant le champ "id_lot" je me suis aperçu qu'il y a des concaténations d'id avec des résultats comme ",53,53,4,1,,53,4,1,3,3,1,1,4,".
Je vais avoir pas mal de boulot pour démêler tout ça!

Quoi qu'il en soit je vous remercie pour votre aide, je vais corriger ces problèmes en espérant que cela résolve ces lenteurs.

gleu

Administrateur

Re : Lenteur d'execution - PostgreSQL 8.2

Ouch, ça sent le tableau de valeurs. Une simple égalité ne marchera pas là-dessus. Bon courage pour démêler tout ça. Et n'hésitez pas à revenir avec d'autres questions.

---

Guillaume.

Christophe-LT

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Bonjour,
Pour faire suite je viens de modifier la première base, la moins lourde : j'ai transformé toutes les clés étrangères en INTEGER puis effectué un Vacuum suivi d'un Reindex.

Voici les résultats avec un EXPLAIN :
Avant - http://explain.depesz.com/s/96r
Après - http://explain.depesz.com/s/6pn

Ces résultats vous semblent-ils corrects?
Merci une nouvelle fois de votre aide!

gleu

Administrateur

Re : Lenteur d'execution - PostgreSQL 8.2

Oui, très clairement. Le VACUUM n'y est pour rien, le REINDEX a pu aider. Mais ce qui a vraiment fait la différence, c'est le passage en integer. Passer de 6 secondes à 23 millisecondes, c'est une belle performance

---

Guillaume.

Christophe-LT

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Et bien ça avance!
Par contre je viens de découvrir deux nouvelles requêtes très lentes pour lesquelles je vais de nouveau avoir besoin de votre aide, ce sont les dernières, promis! Les voici :

select count(*) as total from credits a where iduser='2129' and date between '2012-02-21 12:18' and '2012-03-22 12:18' and not exists (select code from credits_sauvegardes where code=a.code limit 1)
EXPLAIN :

QUERY PLAN

Aggregate  (cost=97581.57..97581.58 rows=1 width=0) (actual time=6949.879..6949.879 rows=1 loops=1)

  ->  Index Scan using user_date_idx on credits a  (cost=0.00..97581.51 rows=23 width=0) (actual time=6949.868..6949.868 rows=0 loops=1)

        Index Cond: ((iduser = 2129) AND (date >= '2012-02-21 12:18:00'::timestamp without time zone) AND (date <= '2012-03-22 12:18:00'::timestamp without time zone))

        Filter: (NOT (subplan))

        SubPlan

          ->  Limit  (cost=0.00..2118.60 rows=1 width=17) (actual time=5.303..5.303 rows=1 loops=1310)

                ->  Seq Scan on credits_sauvegardes  (cost=0.00..2118.60 rows=1 width=17) (actual time=5.302..5.302 rows=1 loops=1310)

                      Filter: ((code)::text = ($0)::text)

Total runtime: 6949.969 ms

select regie, count(*) as total from credits a where date between '2012-02-21 12:18' and '2012-03-22 12:18' and iduser='2129' and not exists (select code from credits_sauvegardes where code=a.code limit 1) group by regie

QUERY PLAN

HashAggregate  (cost=97581.63..97581.64 rows=1 width=16) (actual time=7452.142..7452.142 rows=0 loops=1)

  ->  Index Scan using user_date_idx on credits a  (cost=0.00..97581.51 rows=23 width=16) (actual time=7452.139..7452.139 rows=0 loops=1)

        Index Cond: ((iduser = 2129) AND (date >= '2012-02-21 12:18:00'::timestamp without time zone) AND (date <= '2012-03-22 12:18:00'::timestamp without time zone))

        Filter: (NOT (subplan))

        SubPlan

          ->  Limit  (cost=0.00..2118.60 rows=1 width=17) (actual time=5.686..5.686 rows=1 loops=1310)

                ->  Seq Scan on credits_sauvegardes  (cost=0.00..2118.60 rows=1 width=17) (actual time=5.684..5.684 rows=1 loops=1310)

                      Filter: ((code)::text = ($0)::text)

Total runtime: 7452.317 ms

Merci à nouveau pour votre aide.

gleu

Administrateur

Re : Lenteur d'execution - PostgreSQL 8.2

Merci de créer un nouveau post pour une nouvelle fonction. Pas grave pour ce coup-ci mais pensez-y la prochaine fois.

Ce qui vous coûte cher dans les deux cas, c'est le parcours séquentiel sur la table credits_sauvegarde. Y a-t-il un index sur la colonne code de la table credis_sauvegarde ? De plus, encore une fois, le planificateur a l'air de transformer le type de cette colonne en texte, ce qui est pour le moins étonnant. Comment est définie la table credits_sauvegarde ?

---

Guillaume.

Christophe-LT

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Tout d'abord toutes mes confuses, je pensais bien faire en ne créant pas de nouveau topic vu que les questions sont sur le même sujet.

Effectivement il n'y a pas d'index sur la colonne code de la table credits_sauvegardes.
Par contre credits.code et credits_sauvegardes.code sont tous deux de type character varying (les valeurs insérées sont alphanumériques), je ne comprends pas pourquoi le planificateur effectue une transformation de type.

gleu

Administrateur

Re : Lenteur d'execution - PostgreSQL 8.2

Cette transformation doit être indolore. Essayez avec un index, ça devrait bien améliorer les choses.

---

Guillaume.

Christophe-LT

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Après l'ajout d'un index sur credits_sauvegardes.code la requête passe de 7.45s à 16ms, que dire de plus?

Merci pour votre aide!

Alan2007

Membre

Re : Lenteur d'execution - PostgreSQL 8.2

Merci pour le partage