Discussion :

[HadanMarv]

Bonjour,

Suite à un problème de plantage du moteur postgres avec le message 'Le système est en cours de restauration', j'ai pu constaté que certaines des applications qui accèdent à ma base, lance des select en exclusiveLock.
Je n'arrive pas à comprendre comment en select peut poser un verrou de ce type sur une table.
Dans un premier temps, pour palier au problème, j'ai créer un compte avec seulement les droits select sur la table en question. a ma grande surprise, l'exclusivelock persiste.
Le problème c'est que le traitement retourne 25000 lignes de cette même table et que cela donne un délais au traitement suivant. la requête exécuté dans pgadmin retourne un résultat en plus de 30 secondes. la table posséde 53 colonnes et utilise un espace de stockage d'un peu plus de 130M.
Au total cette table contient 500 000 enregistrements.

D'avance merci de vos lumières.

HadanMarv

[estofilo]

Voir les requêtes ici
https://wiki.postgresql.org/wiki/Lock_Monitoring
pour savoir qui verrouille quoi.

[HadanMarv]

Je me rend compte que mon message n'était probablement pas assez clair.
Donc voici quelques éléments complémentaires.
85 lignes se rajoute dans la table pg_lock pendant l'exécution de ma requête. 84 sont en mode "AccessShareLock", locktype = relation et 1 en "ExclusiveLock" avec un locktype = "virtualxid".
Merci de me dire si vous avez besoin d'autres éléments.

D'autre part, j'ai installé pg_stat_statements, qui me donne des résultat que je ne sais interpréter pour le moment (beaucou plus complet en 9.1 que en 8.4 du reste).
en 8.4 j'ai que la requête avec un nombre d'appel, un temps d'exécution que je suppose * en fonciton du nombre d'appel et un nombre retourné je pense à moins que ce ne soit parcourus.
En 9.1 j'ai plein de colonne en plus comme indiqué ici : Documentation Postgres
mais je n'arrive pas à interpréter correctement les résultats.

De plus, nous avons constaté que dans certains cas l'arrêt brutal du moteur.
Je pense que du tuning est à faire mais j'avoue ne rien y connaitre.

D'avance merci de vos lumières.

HadanMarv

[punkoff]

bonjour,


y a pas une clause FOR UPDATE dans le select ?

[HadanMarv]

malheureusement non.

[estofilo]

Le lock exclusif avec locktype virtualxid signifie juste qu'il y a une transaction en cours, rien de plus.

[HadanMarv]

Très bien merci pour ces informations.

Concernant le second sujet voici ce que j'obtiens à l'exécution de la vue (plantage du moteur postgres) :

ATTENTION: arrêt de la connexion à cause de l'arrêt brutal d'un autre processus serveur
DETAIL: Le postmaster a commandé à ce processus serveur d'annuler la transaction
courante et de quitter car un autre processus serveur a quitté anormalement
et qu'il existe probablement de la mémoire partagée corrompue.
HINT: Dans un moment, vous devriez être capable de vous reconnecter à la base de
données et de relancer votre commande.
********** Erreur **********

J'ai à ma disposition deux moteurs en 8.4 et cela plante sur l'un et fonctionne sur l'autre.

De plus voidi les logs du moteur lors de l'exécution du select sur la vue :

2013-11-29 14:58:54 CET LOG: processus d'écriture en tâche de fond (PID 5824) a ?t? arrêt? par le signal 9 : Killed
2013-11-29 14:58:54 CET LOG: arrêt des autres processus serveur actifs
2013-11-29 14:58:55 CET ATTENTION: arrêt de la connexion à* cause de l'arrêt brutal d'un autre processus serveur
2013-11-29 14:58:55 CET DETAIL: Le postmaster a commandé à* ce processus serveur d'annuler la transaction
courante et de quitter car un autre processus serveur a quitté anormalement
et qu'il existe probablement de la mémoire partagée corrompue.
2013-11-29 14:58:55 CET ASTUCE : Dans un moment, vous devriez être capable de vous reconnecter à* la base de
données et de relancer votre commande.
2013-11-29 14:58:55 CET ATTENTION: arrêt de la connexion à* cause de l'arrêt brutal d'un autre processus serveur
2013-11-29 14:58:55 CET DETAIL: Le postmaster a commandé à* ce processus serveur d'annuler la transaction
courante et de quitter car un autre processus serveur a quitté anormalement
et qu'il existe probablement de la mémoire partagée corrompue.
2013-11-29 14:58:55 CET ASTUCE : Dans un moment, vous devriez être capable de vous reconnecter à* la base de
données et de relancer votre commande.
2013-11-29 14:58:55 CET ATTENTION: arrêt de la connexion à* cause de l'arrêt brutal d'un autre processus serveur
2013-11-29 14:58:56 CET DETAIL: Le postmaster a commandé à* ce processus serveur d'annuler la transaction
courante et de quitter car un autre processus serveur a quitté anormalement
et qu'il existe probablement de la mémoire partagée corrompue.
2013-11-29 14:58:56 CET ASTUCE : Dans un moment, vous devriez être capable de vous reconnecter à* la base de
données et de relancer votre commande.
2013-11-29 14:58:57 CET LOG: tous les processus serveur se sont arr?t?s, r?initialisation
2013-11-29 14:58:57 CET LOG: le système de bases de données a été interrompu ; dernier lancement connu ? 2013-11-29 14:50:51 CET
2013-11-29 14:58:57 CET LOG: le système de bases de données n'a pas été arrêté proprement ; restauration
automatique en cours
2013-11-29 14:58:57 CET LOG: enregistrement de longueur nulle ? 14/2F18F3F8
2013-11-29 14:58:57 CET LOG: la ré-exécution n'est pas nécessaire
2013-11-29 14:58:57 CET LOG: le système de bases de données est prêt pour accepter les connexions
2013-11-29 14:58:57 CET LOG: lancement du processus autovacuum

Si cela peut donner des informations supplémentaires

D'avance merci de vos lumières (vue sur demande parce qu'elle est énorme).

HadanMarv

[estofilo]

Quand le backend plante ce qui est le cas ici il faut d'abord s'assurer qu'on a la dernière version de la branche (SELECT version(); en SQL)

Pour la branche 8.4 la version actuelle est la 8.4.18

Ensuite si la mise à jour vers la dernière version ne corrige pas le problème, voir quelles extensions en dehors du produit lui-même pourraient planter si on en a (postgis par exemple).

Ceci dit d'après cette ligne:

2013-11-29 14:58:54 CET LOG: processus d'écriture en tâche de fond (PID 5824) a ?t? arrêt? par le signal 9 : Killed

Cette erreur est typique de l'OOM (=Out of Memory) killer de Linux qui tue des process plus ou moins au hasard à la sauvage quand le système manque de mémoire.
Quand ça tombe sur postgres, c'est pas de chance.

Cette théorie est confirmable en regardant le log système (genre /var/log/kern.log ou dmesg ou équivalent, ça dépend des distributions).

Dans les bases de données, le consensus est plutôt qu'il faut désactiver l'OOM.
Le sujet est traité rapidement dans la doc de postgres dans les dernières versions:

http://www.postgresql.org/docs/curre...resources.html

Si ça ne suffit pas, il faut regarder comment est configurée la machine qui ne plante pas par rapport à la quantité de RAM, de swap (très utile pour éviter l'OOM), le shared_buffers de postgresql et la mémoire libre de l'OS en usage typique et faire la même conf pour celle qui plante.

[HadanMarv]

Merci pour ces éléments de réponse. Cela nous à permis d'avancer et de constater effectivement le kill du processus postgres par oom.
Suite à investigation il s'avère que c'est belle et bien l'exécution de la vue qui pose le problème.
une requête sur la vue semble prendre 25ms (selon pg_stat_statements).
Deux choses se produisent :
1. le serveur de base prend très chère la mémoire du processus postgres monte jusque 2,6Go de mémoire...
2. Pour une raison inconnu le processus ne redescend pas à son utilisation mémoire initiale (semblant ainsi être la cause du kill par le oom).

Je peux vous fournir la requête de la vue si vous le souhaitez.
En attendant d'autre explication je me suis lancé dans le recodage de la vue en Java.

HadanMarv

[estofilo]

Plusieurs choses

1. Concernant l'OOM personnellement je suis pour le désactiver purement et simplement.

Avec l'OOM désactivé, si postgres n'a pas assez de mémoire il s'en rendra compte tout seul et la requête problématique sera annulée. C'est un moindre mal.

Avec l'OOM activé, toute l'instance postgres redémarre à cause du kill -9 qui en plus est dangereux pour l'intégrité des données.

2. Indépendamment de ça il faut voir si la config de postgresql.conf est bien en rapport avec la mémoire de la machine. Si work_mem est trop élevé, une requête complexe prendra trop de mémoire alors qu'avec work_mem plus petit il utiliserait le disque en espace temporaire.

Si shared_buffers est trop élevé aussi (c'est réservé dès le lancement par postgres pour le cache) il n'y aura plus assez de RAM pour le reste des opérations.

Si c'est bien configuré il y a encore quelques cas de requêtes où postgres ne sait pas utiliser le disque en espace temporaire. Il faudrait un EXPLAIN ANALYZE pour voir.

3. La non-récupération de la mémoire d'un process par l'OS est un problème classique avec le modèle mémoire d'Unix. Les fragments de mémoire libérables entourés par des fragments utilisés ne sont pas restituables. C'est pour ça qu'il faut du swap. Les pages mémoire allouées mais non utiles sont mises en swap et elles redeviennent utiles pour autre chose.

Enfin la version 8.4 se fait vieille (4 versions de retard par rapport à la plus récente) et il y a des améliorations à chaque version sur l'optimiseur/exécuteur.

[HadanMarv]

1. Concernant l'OOM, l'administrateur réseau est pour le laisser même s'il semblait ne pas connaître son existence jusque là.

2. work_mem est en commentaire dans le fichier de conf
shared_buffers est à 1024MB
Pour l'explain analyse de l'éxuction de la vue vous la trouverez en pièce jointe.
La RAM total du serveur est de 4Go et le swap à 5,8Go

3. Ok, merci pour ces éléments, j'avoue que les connaissance en unix d'une manière générale sont relativement limité.

Pour la version du moteur, je l'ai signalé à ma hiérarchie, mais malheureusement des inconnus existent quant aux évolutions du moteur et les différences éventuelles des systèmes d'authentification et de traitement.
à minima je pense pouvoir obtenir la mise à jour 8.14.17 pour le moment en tout cas.

Merci de votre temps

HadanMarv

[HadanMarv]

Il est maintenant acté que le problème se situe au niveau de la requête incluse dans la vue.

Je n'arrive toujours pas à comprendre pourquoi elle prend tellement de RAM sur le serveur.

Afin de partager vous trouverez en pièce jointe la requête incluse dans la vue.
Vous pourrez également l'exécuté sur votre moteur (donnée statique incluse)

Le but de cette requête et de réussir à ventiler la durée d'une matinée de cours et d'une après-midi en fonction de la date de début et de la date de fin et compte tenue de la durée en heures de la formation, de la durée en jours de la formation et également de la durée que j'ai appelé théorique.
Cette durée théorique représente le ratio de temps par jours obtenu par nb_beures_formation / nb_jours_formation.
Je souhaite que si la durée théorique est inférieure à 07h30 alors on prenne une répartition des horaires 3 heures le matin et 4 heures l'après-midi, au delà de 07h30 on prend une répartition 4 heures le matin et 4 heures l'après-midi, en calculant le reste sur la dernière demi-journée.

D'avance merci de vos lumières.

HadanMarv

[estofilo]

Ce qu'on voit dans l'explain graphique de pgadmin, c'est qu'il y a un hashaggregate.

Le hashaggregate est une opération qui ne peut pas utiliser le disque en complément de la mémoire (en fait pas sûr pour les dernières versions, mais en 8.4 c'est certain)

Le planificateur estime la quantité de mémoire nécessaire à cette opération, et en théorie si elle excède work_mem, il ne choisit pas cette méthode.

Mais s'il se plante complètement dans cette estimation mémoire, il peut se lancer dans un hashaggregate qui va aller bien au-delà de la mémoire prévue jusqu'à éventuellement se prendre le plafond. Apparemment c'est ce qui se passerait ici.

Il faudrait vérifier cette hypothèse en faisant

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

 SET enable_hashagg to false;

et réessayer la requête dans la même session. Le planificateur changera de stratégie pour éviter le hashaggregate s'il peut.

Ensuite faire un ANALYZE de la base pour être sûr que les statistiques sont récentes.
Eventuellement booster default_statistics_target qui devrait être à 100 sur la 8.4
On peut mettre 500 par exemple, si c'est un problème de taille d'échantillonnage ça peut aider.

Idéalement il faudrait un EXPLAIN ANALYZE mais si la requête ne va jamais au bout il n'y aura pas de résultat. Le résultat permettrait de comparer les estimations avec la réalité.

[HadanMarv]

Merci pour ces nouveaux éléments de réponse.

j'ai donc tenté les choses dans l'ordre.

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

SET enable_hashagg TO false;

ne produit pas de modification significative.

J'ai ensuite fait l'Analyze sur la base des données.

J'ai ensuite fait un explain analyze (Cf pièce jointe).
J'exécute maintenant la requête sur mon windows en constatant les mêmes effets mise à part que Postgres ne plante pas. Après avoir atteint le pic des 2,6GO il retombe à 4Mo de RAM et produit bien le résultat.

HadanMarv

[estofilo]

dans l'EXPLAIN de pgadmin en screenshot:

http://www.developpez.net/forums/d13...k/#post7595347

il y avait des références à des tables, 2 nested loops, un hashaggregate...

Ils ne sont plus nulle part dans l'EXPLAIN ANALYZE en mode texte, qui par ailleurs ne manipule qu'une seule ligne?

Ca ne doit pas montrer la même chose.

[HadanMarv]

Je comprends votre réponse.
Et effectivement, vous avez raison mais cela s'explique.

Le premier est fourni sur la base de l'exécution de la vue (d'où la référence à des tables).

Le second est une vue plus synthétique du traitement en se basant sur le résultat initial de la première requête qui elle manipule réellement les données des tables.

le point sur lequel je m'interroge le plus est de comprendre pourquoi la seconde requête basé sur une seule ligne fait monter mon process postgres à quelques 2,6Go de RAM.

HadanMarv.

[estofilo]

Si c'est la requête fournie plus haut dans la discussion en pièce jointe je veux bien l'essayer par curiosité mais il manque la fonction ROUNDOMEGA.