Vous n'êtes pas identifié(e).
- Contributions : Récentes | Sans réponse
#1 06/11/2012 11:15:11
- David
- Membre
Bloat ...
Bonjour à tous.
Je viens de recevoir l'équipe d'un projet confronté à un problème d'augmentation excessif de volume d'une table et de ces 2 index.
Cette table fait partie d'un schéma de persistance d'un serveur JBoss, sur un serveur de prod H24.
Cette table est assez sollicitée : 200.000 lignes insérées chaque jour et autant d'effacées (rotation quotidienne des infos).
On se retrouve avec un volume croissant, pas de possibilité d'arrêter JBoss de manière aisée donc ...
J'ai beau scruter la table pg_stat_user_tables assez régulièrement, je constate que ni les stats, ni l'autovacuum n'arrivent à passer (j'avais tout d'abord abaissé la valeur du paramètre autovacum_scale_factor).
Est-ce du à la sollicitation permanente de JBoss et donc aux verrous posé par ses sessions ?
Comme solution au problème, je leur ai proposé de redécouper la table en partition, avec un drop/create régulier de partitions en lieu et place des deletes mais il faudra repasser par une modif du code pour la gestion de ces partitions. En attendant, l'eau monte ...
Merci pour vos conseils.
PS : Version 8.4.x
Hors ligne
#2 06/11/2012 11:38:15
- rjuju
- Administrateur
Re : Bloat ...
Bonjour,
sans autovacuum ou vacuum vous ne pourrez effectivement pas récupérer l'espace disponible (à moins d'utiliser des partitions qui seront supprimées évidemment). Quand vous dites que l'autovacuum ne passe pas, est-ce qu'il se déclenche ? Si oui, est-il pénalisant pour les performances, ou bloqué ... ? Vous pouvez modifier par table les paramètres d'autovacuum afin qu'il puisse s'effectuer.
Julien.
https://rjuju.github.io/
Hors ligne
#3 06/11/2012 12:05:52
- David
- Membre
Re : Bloat ...
Je n'ai pas d'info dans la log sur le déclenchement de l'autovacuum. Il y-a-t-il de l'info ailleurs (table système) ?
Comme indiqué, pour cette table j'ai abaissé le niveau à 10%. Je l'avais calibré pour environ 3 à 4 passages par jour.
Cdlt
Hors ligne
#4 06/11/2012 12:45:54
- arthurr
- Membre
Re : Bloat ...
Bonjour,
J'utilise cette requête :
select
current_database(),
schemaname || '.' || relname as table,
to_char(last_vacuum,'DD-MM-YYYY HH24:mi') as lastvacuum,
to_char(last_autovacuum,'DD-MM-YYYY HH24:mi') as lastautovacuum,
to_char(last_analyze,'DD-MM-YYYY HH24:mi') as lastanalyze,
to_char(last_autoanalyze,'DD-MM-YYYY HH24:mi') as lastautoanalyze
from
pg_stat_user_tables
order by
2
Vous n'aurez pas l'historique du déclenchement de l'autovacuum mais au moins la date du dernier lancement par table
Hors ligne
#5 06/11/2012 12:56:23
- David
- Membre
Re : Bloat ...
Oui, j'ai une requête similaire qui tourne en cron tous les jours avec en plus le suivi de l'évolution des volumes des tables, index.
Donc l'autovacuum n'est jamais repassé sur cette table, ni sur la plupart des autres (sur les 14 au total, 2 ou 3 sont scannées, preuve que le daemon se déclenche quand même) depuis le jour où j'ai recréé la table et les index (transfert dans une table temporaire puis reinsert, recreate des index).
Le dernier passage date donc de 2 semaines, et le ratio de modif est désormais largement dépassé.
Hors ligne
#6 06/11/2012 16:20:24
- David
- Membre
Re : Bloat ...
Autre info, le phénomène ne se produit que sur une seule des 2 bases créées sur le même cluster !?!
Les colonnes n_tup_ins, n_tup_del, etc... restent à '0' alors qu'il y a a peu près 200.000 insert par jour dans la 1ère table.
Le nombre de lignes n'est pas correct non plus (cf ci-dessous).
base1=# select relname,seq_tup_read,n_tup_ins,n_tup_upd,n_tup_del,n_tup_hot_upd,n_live_tup,n_dead_tup,last_autovacuum,last_autoanalyze from pg_stat_all_tables where relname like '%tres%';
relname | seq_tup_read | n_tup_ins | n_tup_upd | n_tup_del | n_tup_hot_upd | n_live_tup | n_dead_tup | last_autovacuum | last_autoanalyze
----------------------+--------------+-----------+-----------+-----------+---------------+------------+------------+-------------------------------+-------------------------------
tres1 | 35937175 | 350087 | 0 | 0 | 0 | 395251 | 0 | 2012-10-24 08:08:15.264593+00 |
tres2 | 22404351 | 59210 | 0 | 59349 | 0 | 233 | 0 | 2012-10-23 12:06:29.676185+00 | 2012-10-23 12:06:29.676185+00
tres3 | 52762897978 | 26307205 | 0 | 26275065 | 0 | 36634 | 0 | 2012-10-23 12:14:46.377767+00 | 2012-10-23 12:14:46.377767+00
base1=# select count(*) from tres1;
count
--------
444375
(1 ligne)
Les stats du cluster indiquent bien de l'activité sur CHACUNE des bases et une requête à intervalle régulier souligne bien cette activité (tup_inserted, tup_updated ):
postgres=# select * from pg_stat_database ;
datid | datname | numbackends | xact_commit | xact_rollback | blks_read | blks_hit | tup_returned | tup_fetched | tup_inserted | tup_updated | tup_deleted
-------+-----------+-------------+-------------+---------------+--------------+--------------+--------------+-------------+--------------+-------------+-------------
....
...
16390 | base1 | 12 | 100205231 | 1688 | 654814538597 | 114046341945 | 638065108162 | 1279110249 | 352344801 | 13979769 | 351056792
16391 | base2 | 3 | 6252807 | 4604 | 52260426 | 877573728 | 9650447251 | 247968875 | 52513721 | 1544963 | 51502840
L'autovacuum positionnée à 10%:
base1=# \d+ tres1
Table « public.tres1 »
Colonne | Type | Modificateurs | Stockage | Description
--------------+-----------------------------+---------------+----------+-------------
...
...
Index :
"pk_tres1" PRIMARY KEY, btree (id)
"i_tres1_1" btree (coldd, dateo)
Contient des OID: non
Options: autovacuum_vacuum_scale_factor=0.1
Dernière modification par David (06/11/2012 16:20:57)
Hors ligne
#7 06/11/2012 17:53:59
- arthurr
- Membre
Re : Bloat ...
que donne :
show track_counts;
sur la base qui pose problème ?
Hors ligne
#8 06/11/2012 18:03:28
- David
- Membre
Re : Bloat ...
track_counts= ON
Mais ce que je ne comprends absolument pas c'est pourquoi les tables de l'autre base qui sont sur le même cluster sont bien analysées, et même 3 tables de cette même base.
Il resterait la possibilité d'avoir désactivé ce paramètre au niveau de chaque session mais je ne pense pas que les développeurs soient allés aussi loin ?????
Hors ligne
#9 06/11/2012 18:30:21
- arthurr
- Membre
Re : Bloat ...
vous pouvez vous connecter en plsql et faire "show all;" sur chaque base pour voir si il y a une différence de configuration.
(le track_counts peut être modifié pour une base du cluster par exemple : alter database ??? set track_counts to 'off')
Hors ligne
#10 06/11/2012 18:37:20
- David
- Membre
Re : Bloat ...
Non pas de différence notée.
Hors ligne
#11 07/11/2012 09:51:40
- gleu
- Administrateur
Re : Bloat ...
À moins d'avoir des verrous très bloquants (genre un ExclusiveLock, qui arrive généralement très peu souvent), le VACUUM et le ANALYZE ne sont pas bloquables. D'ailleurs, je pense que si vous lancez vous-même un VACUUM, il s'exécutera sans problème (plus ou moins rapidement, mais sans blocage).
L'enregistrement des statistiques n'est pas non plus bloquable. En dehors du paramètre track_counts, rien ne peut empêcher leur récupération et leur écriture. Il faudrait mettre en place un petit outil (comme pgstats) pour récupérer régulièrement les statistiques au format CSV. Il faudra le modifier pour qu'il récupère en plus les statistiques spécifiques des tables tres*. Ça permettra de comprendre un peu mieux ce qu'il se passe. Si vous ne constatez aucune activité sur une table, le mieux serait de tracer toutes les requêtes (ou uniquement les requêtes DDL et DML, avec log_statement) pour savoir exactement ce qui est exécuté.
Guillaume.
Hors ligne
#12 07/11/2012 11:30:46
- David
- Membre
Re : Bloat ...
Bonjour à tous.
"... qui arrive généralement très peu souvent... "
Ah, effectivement, je note en permanence ce type de lock par le même process id depuis ce matin (certainement depuis plus):
base1=# select
pg_stat_activity.datname,pg_class.relname, pg_locks.mode, pg_locks.granted,
pg_stat_activity.usename,substr(pg_stat_activity.current_query,1,30), pg_stat_activity.query_start,
age(now(),pg_stat_activity.query_start) as "age", pg_stat_activity.procpid
from pg_stat_activity,pg_locks left
outer join pg_class on (pg_locks.relation = pg_class.oid)
where pg_locks.pid=pg_stat_activity.procpid order by query_start;
datname | relname | mode | granted | usename | substr | query_start | age | procpid
---------+----------------------------+-----------------+---------+----------+-------------------------+-------------------------------+-----------------+---------
....
....
base1| | ExclusiveLock | t | base1| <IDLE> in transaction | 2012-11-07 08:43:05.609366+00 | 00:00:11.403627 | 23932
....
....
[postgres@db log]$ ps -ef | grep 23932
postgres 23932 10985 1 Oct23 ? 04:29:47 postgres: base1 base1 xxx.xxx.xx.xxx(42799) idle in transaction
base1=# SELECT locktype, database::regclass, relation::regclass,page, tuple, virtualxid, transactionid, classid, objid,objsubid, virtualtransaction, pid, mode, granted FROM pg_locks ;
locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted
------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+-----------------+---------
virtualxid | | | | | 4/324249 | | | | | 4/324249 | 12948 | ExclusiveLock | t
virtualxid | | | | | 2/1851149 | | | | | 2/1851149 | 23932 | ExclusiveLock | t
La doc indique : "ExclusiveLock = Ce mode de verrouillage n'est acquis automatiquement sur des tables par aucune commande PostgreSQL™. "
D'où peut venir le verrou Exclusif ?
Serait-ce cette session datée du 23/10 (c'est la date de démarrage du serveur et la dernière fois où l'autovacuum a pu passer sur ces tables) ?
De plus, dans la log du serveur, je trouve uniquement et très souvent ce message d'erreur qui me fait penser que la dernière transaction de la session en cours ne s'est pas cloturée de manière satisfaisante:
2012-11-07 08:38:02 GMT::::base1:base1::BEGINATTENTION: une transaction est déjà en cours
2012-11-07 08:38:02 GMT::::base1:base1::BEGINATTENTION: une transaction est déjà en cours
2012-11-07 08:38:02 GMT::::base1:base1::BEGINATTENTION: une transaction est déjà en cours
2012-11-07 08:38:02 GMT::::base1:base1::BEGINATTENTION: une transaction est déjà en cours
Concernant ce dernier point, je ne pense pas qu'il s'agisse du même type de verrou (?)
Comment puis-je retrouver plus d'infos sur le process client ?
Hors ligne
#13 07/11/2012 11:46:53
- gleu
- Administrateur
Re : Bloat ...
Ce que je voulais dire, c'est qu'il est peu fréquent que cela arrive sur des tables. Là, vu ce que vous montrez, il s'agit d'un verrou exclusif sur un id de transaction virtuelle pour que cet identifiant ne soit pas donné à une autre session. En gros, ça ne gêne rien ici. Si la transaction date du 23 octobre, très clairement, il y a un soucis au niveau applicatif. Cela sous-entend que cet applicatif n'a pas terminé la transaction (ce que laisse supposer les logs que vous montrez). Il n'y a eu ni COMMIT ni ROLLBACK de la transaction précédente.
Ce qu'il serait intéressant, c'est de savoir quel type de verrou où les sessions qui sont en "idle in transaction".
Guillaume.
Hors ligne
#14 07/11/2012 12:27:20
- David
- Membre
Re : Bloat ...
Guillaume, je n'ai pas compris ce que vous vouliez dire: "ce qu'il serait intéressant, c'est de savoir quel type de verrou où les sessions qui sont en "idle in transaction".
Je n'ai qu'une seule session "IDLE in rtansaction"
Ceci.
postgres=# select
pg_stat_activity.datname,pg_class.relname,pg_locks.transactionid, pg_locks.mode, pg_locks.granted,
pg_stat_activity.usename,substr(pg_stat_activity.current_query,1,30), pg_stat_activity.query_start,
age(now(),pg_stat_activity.query_start) as "age", pg_stat_activity.procpid
from pg_stat_activity,pg_locks full
join pg_class on (pg_locks.relation = pg_class.oid)
where pg_locks.pid=pg_stat_activity.procpid and substr(pg_stat_activity.current_query,1,30) like '%IDLE%' order by query_start;
datname | relname | transactionid | mode | granted | usename | substr | query_start | age | procpid
---------+---------+---------------+---------------+---------+---------+-----------------------+-------------------------------+-----------------+---------
base1 | | | ExclusiveLock | t | base1| <IDLE> in transaction | 2012-11-07 10:16:56.637027+00 | 00:01:44.220869 | 23932
(1 ligne)
Hors ligne
#15 07/11/2012 17:57:59
- gleu
- Administrateur
Re : Bloat ...
Exécutez cette requête :
SELECT * FROM pg_locks WHERE pid=23932;
Cela donnera tous les verrous conservés par ce processus.
Guillaume.
Hors ligne
#16 07/11/2012 18:39:52
- David
- Membre
Re : Bloat ...
Ca bouge pas mal selon l'activité avec plus ou moins de tables listées (ici 4) mais pas de choses figées.
?
locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted
------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+-----------------+---------
relation | 16390 | 278637 | | | | | | | | 2/1885342 | 23932 | AccessShareLock | t
relation | 16390 | 278643 | | | | | | | | 2/1885342 | 23932 | AccessShareLock | t
relation | 16390 | 278661 | | | | | | | | 2/1885342 | 23932 | AccessShareLock | t
relation | 16390 | 278663 | | | | | | | | 2/1885342 | 23932 | AccessShareLock | t
virtualxid | | | | | 2/1885342 | | | | | 2/1885342 | 23932 | ExclusiveLock | t
Hors ligne
#17 07/11/2012 19:11:00
- gleu
- Administrateur
Re : Bloat ...
Et de toute façon, des verrous en AccessShareLock ce qui ne peut pas bloquer un VACUUM ou un ANALYZE, qu'il soit manuel ou lançé par autovacuum.
Guillaume.
Hors ligne