Vous n'êtes pas identifié(e).
Pages : 1
Bonjour la communauté,
Pour mon premier post sur le forum que je suis de plus en plus près, je voudrais en savoir plus sur les bonnes pratiques à adopter sur une base postgresql en souffrance.
J'ai une bdd en version 8.4.7 sous ubuntu 9.10 dont le dump répresente 1.5 Go (de taille normale imho),
Après l'installation de base, j'ai isolé l'ensemble des data sur une partition disque différente de la partition système (c'est d'ailleur la seule modif apportée au fichier postgresql.conf)
Le contexte
-l'applicatif tourne sur la même machine (gandi 2 coeurs 1 Go de ram, 512 Mo pour l'appli JEE) et exploite c3p0 pour pooler les connections
-la base est sollicitée quotidiennement sur une période relativement courte (23h00 - 3h00) notamment pour de l'injection de données dans une table (en moyenne 5 - 9M d'enregistrements quotidien sur cette table, avec une rotation de 2 semaines, soit à peu près 110 - 120 M d'enregistrements)
La maintenance opérationnelle
Les opérations suivantes sont réalisées quotidiennement ou hebdomadairement
- dump complet (via backup-manager)
- observation des logs (rien à observer à part des evènements fataux, la configuration étant vierge)
- sur la base des stats applicatives (temps min / max /moyen de traitement d'une requête http) => isolation des n requêtes http les plus lentes => recensement des requêtes SQL => explain sur ces requêtes => correctif applicatif (reformulation de la requête, découpage fonctionnel différent) ou ajout d'index.
Les symptômes
La stack appli / BDD tourne "normalement" (temps de réponse utilisateur acceptable) depuis 18 mois maintenant, j'observe cependant depuis quelques jours des timeouts http sur des accès en consultation de données. En regardant de plus près, je constate que l'activité appli est nulle, et l'activité bdd un plus importante 3.8 - 4% cpu max, sans plus.
l'affichage des processus postgres (ps -ef ...) me retourne plusieurs (mais pas tous) processus en INSERT waiting et un ou deux en SELECT
l'affichage détaillé sous psql (http://www.lunatech-research.com/archiv … greSQL-tid) m'informe des transactions en cours, mais j'avoue que je ne sais pas trop quoi en conclure du point de vue bdd
Je constate enfin que l'utilisation de pg_cancel_backend (http://www.postgresonline.com/journal/a … -Ends.html) me permet de débloquer la situation, temporairement.
Merci de m'avoir lu jusque là !
Alors je me permets de poster pour :
1 - avoir vos commentaires conseils sur la methodo suivie pour déployer et maintenir la base en l'état.
2 - connaître l'approche la plus efficace pour addresser ce type de comportements observés, mais du point de vue DB (rendre les logs plus verbeux, executer des traitements de maintenance, embaucher un vrai dba...)
Je tiens à préciser que je ne suis pas dbA, ni développeur, ni ingé sys, mais un peu de tout ca au sein de ma petite pme.
Merci pour vos commentaires et conseils
E.
Hors ligne
Le déploiement de la base semble bon, quoiqu'il pourrait être facilement amélioré, notamment par la configuration de PostgreSQL. Néanmoins, cela ne devrait pas corriger le problème que vous avez. Pour traiter votre problème de blocage, et notamment les INSERT en waiting, il faudrait nous fournir plus d'informations pour qu'on puisse vous aider. Notamment avoir le contenu de pg_stat_activity (qui vous indique les INSERT en waiting) pourrait nous mettre sur la piste.
En gros, vous avez un processus qui bloque une partie des autres processus et le but est de trouver lequel et ce qu'il fait pour les bloquer. La solution se trouve dans pg_stat_activity et pg_locks. Et le problème est certainement dû à l'application et non à PostgreSQL.
Guillaume.
Hors ligne
Bonjour,
Que donne un "select * from pg_stat_activity;" lorsque la base "bloque" ?
Avez vous des erreurs dans vos logs (Deadlock) ?
Quand vous observez le % de CPU utilisé, qu'avez vous en %wa ?
Remarques concernant les actions de maintenance :
1/ temps min / max /moyen de traitement d'une requête http => log_min_duration du fichier postgresql permet de logger les requêtes trop longues
2/ Quid des vacuum / analyse ?
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
2Hors ligne
Merci pour ces retours,
J'ai en ce moment même la sortie ps qui me rend ceci
postgres 11328 1 0 08:48 ? 00:00:01 /usr/lib/postgresql/8.4/bin/postgres -D /srv/sdhost-app/pgdata/main -c config_file=/etc/postgresql/8.4/main/postgresql.conf
postgres 11331 11328 0 08:48 ? 00:00:06 postgres: writer process
postgres 11332 11328 0 08:48 ? 00:00:01 postgres: wal writer process
postgres 11333 11328 0 08:48 ? 00:00:01 postgres: autovacuum launcher process
postgres 11334 11328 0 08:48 ? 00:00:03 postgres: stats collector process
postgres 11710 11328 0 09:01 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(35923) idle
postgres 11711 11328 0 09:01 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(35924) idle
postgres 11914 11328 0 09:26 ? 00:00:52 postgres: sensor sensordb1 127.0.0.1(51881) idle
postgres 11915 11328 0 09:26 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(51882) idle
postgres 11917 11328 0 09:26 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(51884) idle
postgres 11918 11328 0 09:26 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(51885) idle
postgres 11920 11328 0 09:26 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(51887) idle
postgres 13297 11328 0 12:42 ? 00:00:06 postgres: sensor sensordb1 127.0.0.1(39026) idle
postgres 13298 11328 0 12:42 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(39027) idle
postgres 13299 11328 0 12:42 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(39028) idle
postgres 13302 11328 0 12:42 ? 00:00:07 postgres: sensor sensordb1 127.0.0.1(39031) idle
postgres 13304 11328 0 12:42 ? 00:00:48 postgres: sensor sensordb1 127.0.0.1(39033) idle
postgres 16205 11328 0 13:22 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(39690) idle
postgres 16206 11328 0 13:22 ? 00:00:31 postgres: sensor sensordb1 127.0.0.1(39691) INSERT waiting
postgres 16207 11328 0 13:22 ? 00:00:26 postgres: sensor sensordb1 127.0.0.1(39692) SELECTJ'en conclus après plusieurs secondes d'attente qu'un cas de blocage est en cours
@Arthurr
-pas d'erreur de deadlock dans les logs
-what is %wa ? un top me sort ceci
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
16207 postgres 20 0 51864 39m 35m D 4 3.8 0:30.26 postgresVoici ce qui ressort de la consultation de pg_stat_activity
select procpid, waiting, xact_start, query_start, backend_start from pg_stat_activity;
procpid | waiting | xact_start | query_start | backend_start
---------+---------+-------------------------------+-------------------------------+-------------------------------
13304 | f | | 2011-09-21 15:17:22.03169+00 | 2011-09-21 12:42:37.973344+00
16963 | f | 2011-09-21 15:17:57.914497+00 | 2011-09-21 15:17:57.914497+00 | 2011-09-21 15:14:11.88781+00
13297 | f | | 2011-09-21 15:12:19.089292+00 | 2011-09-21 12:42:37.892173+00
13298 | f | | 2011-09-21 13:22:58.327495+00 | 2011-09-21 12:42:37.895526+00
13299 | f | | 2011-09-21 13:22:58.326579+00 | 2011-09-21 12:42:37.898187+00
16206 | t | 2011-09-21 15:09:43.672439+00 | 2011-09-21 15:09:45.756467+00 | 2011-09-21 13:22:57.775099+00
16207 | f | 2011-09-21 14:57:49.827326+00 | 2011-09-21 14:57:50.002233+00 | 2011-09-21 13:22:57.775471+00
16297 | f | | 2011-09-21 14:19:38.789846+00 | 2011-09-21 13:38:07.210547+00
13302 | f | | 2011-09-21 13:22:57.883614+00 | 2011-09-21 12:42:37.952311+00
16205 | f | | 2011-09-21 13:22:57.930659+00 | 2011-09-21 13:22:57.773747+00
11711 | f | | 2011-09-21 09:26:04.449413+00 | 2011-09-21 09:01:04.774461+00
11710 | f | | 2011-09-21 09:26:04.439868+00 | 2011-09-21 09:01:04.774133+00
11914 | f | | 2011-09-21 12:42:13.09521+00 | 2011-09-21 09:26:03.21994+00
11915 | f | | 2011-09-21 09:26:04.43964+00 | 2011-09-21 09:26:03.221895+00
11917 | f | | 2011-09-21 09:26:04.444564+00 | 2011-09-21 09:26:03.356444+00
11918 | f | | 2011-09-21 09:26:03.366232+00 | 2011-09-21 09:26:03.363535+00
11920 | f | | 2011-09-21 09:26:03.369445+00 | 2011-09-21 09:26:03.366658+00
procpid 16963 : select procpid, waiting, xact_start, query_start...
procpid 16206 : insert into snsrRecord
procpid 16207 : select record0_.id as ..... from snsrRecord where record0_ where ... (plusieurs critères, dont deux sur des tables liées et une temporelle - recorddate between X an Y)Enfin le statut sur l'état des operations de maintenance interne
current_database | table | lastvacuum | lastautovacuum | lastanalyze | lastautoanalyze
------------------+------------------------------+------------------+------------------+------------------+------------------
sensordb1 | public.databasechangelog | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.databasechangeloglock | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.patchlevel | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrbinding | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrbroadcast | 06-09-2011 08:00 | | 06-09-2011 08:00 | 20-09-2011 19:08
sensordb1 | public.snsrcfgvar | 06-09-2011 08:00 | | 06-09-2011 08:00 | 30-08-2011 15:01
sensordb1 | public.snsrcmd | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrcmd_args | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrcomdqueue | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrconsolidation | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrcustomer | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrdevice | 06-09-2011 08:00 | 21-09-2011 00:08 | 06-09-2011 08:00 | 21-09-2011 05:37
sensordb1 | public.snsrdevicecfg | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrdevicetypeassoc | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrexport | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrfactorytest | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrfactorytest_tests | 06-09-2011 08:00 | | 06-09-2011 08:00 | 19-09-2011 17:34
sensordb1 | public.snsrmember | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrmemberprofile | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrmetric | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrmetricvar | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrmodeldef | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrnode | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsroperation | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrorganisation | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrpackage | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrpermassign | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrpicture | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrprobalert | 06-09-2011 08:00 | | 06-09-2011 08:00 | 15-09-2011 09:48
sensordb1 | public.snsrprobcond | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrprobe | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrprobecfg | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrproduct | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrprofile | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrprop | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrrecord | 06-09-2011 08:07 | 20-09-2011 23:11 | 06-09-2011 08:10 | 18-09-2011 01:52
sensordb1 | public.snsrrelease | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrsite | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrsiteway | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrstatusvar | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrsystem | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrtargetmetric | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrtypedef | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrvariable | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrvendor | 06-09-2011 08:00 | | 06-09-2011 08:00 |
sensordb1 | public.snsrversion | 06-09-2011 08:00 | | 06-09-2011 08:00 |Les récentes occurence de vaccum / analyse semblent en phase avec les tables les plus régulièrement sollicitées au niveau applicatif
Je modifie la conf pour tracer les requêtes de plus de X ms
E.
Hors ligne
Alors, le processus qui exécute le INSERT est bien en attente d'un verrou. Pour savoir quel verrou, il faut trouver le processus qui le bloque. Ici, il semble que ce soit le SELECT car tous les autres processus indiquent idle. Il faudrait regarder le contenu de la table pg_locks. La prochaine fois que cela se produit, pouvez-vous fournir le contenu complet de pg_stat_activity (en fait il manque surtout la colonne current_query) ainsi que le contenu complet de pg_locks ? Merci.
Guillaume.
Hors ligne
Bonjour Guillaume,
pour des questions de lisibilité, les requêtes sont partielles
select procpid, waiting, xact_start, case when length(current_query) > 40 then substring(current_query for 20) || '...' || substring(current_query from (length(current_query) - 19) for 20) else current_query end as query,query_start, backend_start from pg_stat_activity;
---------+---------+-------------------------------+---------------------------------------------+-------------------------------+-------------------------------
24994 | f | | <IDLE> | 2011-09-22 08:50:55.843264+00 | 2011-09-22 08:40:39.864567+00
17706 | f | | <IDLE> | 2011-09-21 16:10:59.431737+00 | 2011-09-21 16:10:59.219198+00
17707 | f | | <IDLE> | 2011-09-21 16:10:59.431568+00 | 2011-09-21 16:10:59.222115+00
17708 | f | | <IDLE> | 2011-09-21 16:10:59.437048+00 | 2011-09-21 16:10:59.433722+00
17709 | f | | <IDLE> | 2011-09-21 16:10:59.439149+00 | 2011-09-21 16:10:59.436508+00
17710 | f | | <IDLE> | 2011-09-21 16:10:59.442018+00 | 2011-09-21 16:10:59.4399+00
17711 | f | | <IDLE> | 2011-09-22 01:54:12.438279+00 | 2011-09-21 16:10:59.442741+00
17713 | f | | <IDLE> | 2011-09-22 08:40:30.040956+00 | 2011-09-21 16:10:59.447902+00
17715 | f | | <IDLE> | 2011-09-22 08:40:27.187039+00 | 2011-09-21 16:10:59.451399+00
17719 | f | | <IDLE> | 2011-09-22 01:54:14.501713+00 | 2011-09-21 16:10:59.460876+00
24989 | f | | <IDLE> | 2011-09-22 08:40:39.851391+00 | 2011-09-22 08:40:39.7986+00
24990 | f | | <IDLE> | 2011-09-22 08:40:39.851561+00 | 2011-09-22 08:40:39.801836+00
24991 | f | 2011-09-22 08:50:31.70157+00 | select record0_.id a...ord0_.recorddate asc | 2011-09-22 08:50:31.814156+00 | 2011-09-22 08:40:39.804197+00
24992 | t | 2011-09-22 08:51:34.493436+00 | insert into snsrReco... $3, $4, $5, $6, $7) | 2011-09-22 08:51:36.27359+00 | 2011-09-22 08:40:39.852488+00
24993 | f | | <IDLE> | 2011-09-22 08:40:40.254967+00 | 2011-09-22 08:40:39.854626+00les deux requêtes en détails :
select record0_.id as id13_, record0_.broadcast_id as broadcast4_13_, record0_.owner_id as owner5_13_, record0_.recorddate as recorddate13_, record0_.recordvalue as recordva3_13_, record0_.recordvar_id as recordvar6_13_, record0_.target_id as target7_13_ from snsrRecord record0_ where record0_.recordvar_id=$1 and record0_.owner_id=$2 and (record0_.recorddate between $3 and $4) order by record0_.recorddate ascEt
insert into snsrRecord (broadcast_id, owner_id, recorddate, recordvalue, recordvar_id, target_id, id) values ($1, $2, $3, $4, $5, $6, $7)Structurellement, la table snsrRecord est liée à plusieurs tables :
Column | Type | Modifiers
--------------+-----------------------------+-----------
id | bigint | not null
recorddate | timestamp without time zone |
recordvalue | character varying(255) |
broadcast_id | bigint |
owner_id | bigint |
recordvar_id | bigint |
target_id | bigint |
Indexes:
"snsrrecord_pkey" PRIMARY KEY, btree (id)
"idx_record_broadcast" btree (broadcast_id)
"idx_record_bug117" btree (owner_id, recordvar_id, recorddate)
"idx_record_owner" btree (owner_id)
"idx_record_recorddate" btree (recorddate)
"idx_record_target" btree (target_id)
"idx_record_var" btree (recordvar_id)
Foreign-key constraints:
"fk_record_broadcast" FOREIGN KEY (broadcast_id) REFERENCES snsrbroadcast(id)
"fk_record_owner" FOREIGN KEY (owner_id) REFERENCES snsrdevice(id)
"fk_record_target" FOREIGN KEY (target_id) REFERENCES snsrdevice(id)
"fk_record_var" FOREIGN KEY (recordvar_id) REFERENCES snsrvariable(id)Et côté pg_locks, voici ce que me sort la requête suivante (select (*) me renvoie plus de 300 enregistrements):
select
locktype, database, relation, page, tuple, transactionid, virtualtransaction, mode, granted,
relname, relkind,
datname, usename,
case
when length(current_query) > 40
then substring(current_query for 20) || '...'
|| substring(current_query from (length(current_query) - 19) for 20)
else current_query
end as query,
waiting, query_start, client_addr, client_port
from pg_locks
left outer join pg_class on oid = relation
left outer join pg_stat_activity on pid = procpid
order by pid;Résultat (ne porte que sur le select, j'ai du procéder à un nouveau "déblocage"):
locktype | database | relation | page | tuple | transactionid | virtualtransaction | mode | granted | relname | relkind | datname | usename | query | waiting | query_start | client_addr | client_port
---------------+----------+----------+------+-------+---------------+--------------------+------------------+---------+---------+---------+-----------+---------+---------------------------------------------+---------+-------------------------------+-------------+-------------
relation | 26166 | 26346 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27593 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27538 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27615 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27557 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26549 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 1528078 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26555 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26551 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26523 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26358 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 1528075 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26385 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26385 | | | | 1/5452 | RowExclusiveLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 1528077 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
transactionid | | | | | 2275951 | 1/5452 | ExclusiveLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27550 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 28020 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27558 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27559 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26553 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26361 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26507 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26259 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26491 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
virtualxid | | | | | | 1/5452 | ExclusiveLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27563 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26543 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27551 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27551 | | | | 1/5452 | RowExclusiveLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26391 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27546 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27543 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 1528073 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26559 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27539 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27535 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26505 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26265 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27537 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27545 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26295 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 1528074 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27549 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26379 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27536 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26557 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26557 | | | | 1/5452 | RowExclusiveLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26367 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26373 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27617 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27514 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27547 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 1528076 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27548 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26521 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27592 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 27616 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26280 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26513 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068
relation | 26166 | 26298 | | | | 1/5452 | AccessShareLock | t | | | sensordb1 | sensor | select record0_.id a...ord0_.recorddate asc | f | 2011-09-22 09:05:13.962259+00 | 127.0.0.1 | 60068Mon interprétation
En l'état, la lecture des données de la table snsrRecord prend un temps infini et est à l'origine du blocage progressif des autres requêtes (insertion, maj). J'avais dans l'idée de partir sur un explain de la requête en question pour comprendre l'origine de la lenteur, qu'est ce que je dois comprendre de la sortie précedente concernant les nombreux locks rien que sur la lecture ?
Merci encore
Hors ligne
Sous PostgreSQL, un lecteur ne bloque pas un écrivain, et un écrivain ne bloque pas un lecteur (PostgreSQL est MVCC http://docs.postgresql.fr/9.0/mvcc.html)
Il est donc peu probable qu'une lecture qui prend un temps infini bloque même des updates. Du moins pas dans un cas normal (il faudrait un SELECT qui verrouille des enregistrements, donc soit un SELECT FOR UPDATE, soit un SELECT qui appelle une procédure stockée qui fait des mises à jour ou des LOCK TABLE).
Il faut vraiment le contenu de pg_lock entier… là il n'y a pas d'enregistrement avec granted à false. Et vérifier aussi qu'il y a bien une requête en waiting à 't' dans pg_stat_activity. Sinon, il n'y aura de toutes façons pas d'enregistrement de pg_lock avec un granted à false.
Les verrous qu'on voit ici sont
- soit des accessshare, qui empêchent simplement la prise de verrou exclusif par une autre transaction sur l'objet (une table vraisemblablement), histoire que l'opération en cours puisse se faire (un select par exemple)
- soit des exclusive sur des transactions ou des transactions virtuelles, c'est ce qui est utilisé pour qu'une transaction en attende une autre (quand le moteur voit par exemple qu'une session a besoin de savoir ce qu'une autre a fait avant de pouvoir continuer… un update bloqué par un autre par exemple)
- un rowexclusive, qui indique que sur cet objet, il y a une mise à jour. ça empêche d'autres sessions de faire des vacuum full, truncate, create index, alter table sur cette table tant que le verrou est tenu
Donc rien que du normal. Aucun de ces verrous (malgré le nom rowexclusive) n'est un verrou d'enregistrement.
Marc.
Hors ligne
Merci Marc, je tombe les pg_lock alors
J'ai un select et 3 inserts waiting
postgres 17687 1 0 Sep21 ? 00:00:02 /usr/lib/postgresql/8.4/bin/postgres -D /srv/sdhost-app/pgdata/main -c config_file=/etc/postgresql/8.4/main/postgresql.conf
postgres 17689 17687 0 Sep21 ? 00:00:17 postgres: writer process
postgres 17690 17687 0 Sep21 ? 00:00:05 postgres: wal writer process
postgres 17691 17687 0 Sep21 ? 00:00:03 postgres: autovacuum launcher process
postgres 17692 17687 0 Sep21 ? 00:00:06 postgres: stats collector process
postgres 17706 17687 0 Sep21 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(49816) idle
postgres 17707 17687 0 Sep21 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(49817) idle
postgres 17710 17687 0 Sep21 ? 00:00:15 postgres: sensor sensordb1 127.0.0.1(49820) INSERT waiting
postgres 17711 17687 0 Sep21 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(49821) idle
postgres 17713 17687 0 Sep21 ? 00:00:55 postgres: sensor sensordb1 127.0.0.1(49823) idle
postgres 17715 17687 0 Sep21 ? 00:00:32 postgres: sensor sensordb1 127.0.0.1(49825) idle
postgres 17719 17687 0 Sep21 ? 00:03:53 postgres: sensor sensordb1 127.0.0.1(49829) idle
postgres 25278 17687 0 09:03 ? 00:00:11 postgres: sensor sensordb1 127.0.0.1(60064) idle
postgres 25279 17687 0 09:03 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(60065) idle
postgres 25280 17687 0 09:03 ? 00:00:02 postgres: sensor sensordb1 127.0.0.1(60066) idle
postgres 25281 17687 0 09:03 ? 00:00:04 postgres: sensor sensordb1 127.0.0.1(60067) SELECT
postgres 25634 25579 0 09:39 pts/2 00:00:00 /usr/lib/postgresql/8.4/bin/psql
postgres 25636 17687 0 09:39 ? 00:00:01 postgres: sensor sensordb1 127.0.0.1(54385) INSERT waiting
postgres 25637 17687 0 09:39 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(54386) idle
postgres 25638 17687 0 09:39 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(54387) idle
postgres 25639 17687 0 09:39 ? 00:00:00 postgres: sensor sensordb1 127.0.0.1(54388) INSERT waiting
postgres 25651 17687 0 09:41 ? 00:00:00 postgres: postgres sensordb1 [local] idle locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted
---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+------------------+---------
relation | 26166 | 27586 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26543 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26553 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27551 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26379 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26555 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26361 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26551 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26358 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 1528075 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
virtualxid | | | | | 5/136 | | | | | 5/136 | 25716 | ExclusiveLock | t
relation | 26166 | 27536 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26507 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 6/144 | 17710 | RowShareLock | t
relation | 26166 | 26491 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27563 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 1528078 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 26543 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26549 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 26553 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27551 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26361 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26557 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26557 | | | | | | | | 14/4861 | 25281 | RowExclusiveLock | t
relation | 26166 | 26507 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 18/75 | 25636 | RowShareLock | t
relation | 26166 | 26491 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27563 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26367 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26373 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 6/144 | 17710 | RowShareLock | t
relation | 26166 | 27617 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27550 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27514 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27547 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27557 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 1528076 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27548 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 1528077 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 27558 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27559 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26521 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27592 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 16385 | 1259 | | | | | | | | 8/2579 | 25717 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 18/75 | 25636 | RowShareLock | t
relation | 26166 | 27538 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27550 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27615 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
virtualxid | | | | | 18/75 | | | | | 18/75 | 25636 | ExclusiveLock | t
relation | 26166 | 27616 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26280 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26513 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
transactionid | | | | | | 2275997 | | | | 1/5474 | 25639 | ExclusiveLock | t
relation | 26166 | 26346 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26298 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 1528077 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 27558 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27559 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
transactionid | | | | | | 2276003 | | | | 18/75 | 25636 | ExclusiveLock | t
relation | 26166 | 1528078 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 27586 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26543 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26549 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 27551 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26555 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26551 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
transactionid | | | | | | 2276025 | | | | 6/144 | 17710 | ExclusiveLock | t
relation | 26166 | 26391 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26358 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 27546 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 1528075 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 27543 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26507 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 1/5474 | 25639 | RowShareLock | t
relation | 26166 | 26491 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27563 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 1528078 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 27586 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 1528073 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26559 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26549 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 26553 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26555 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26361 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26551 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
virtualxid | | | | | 8/2579 | | | | | 8/2579 | 25717 | ExclusiveLock | t
relation | 26166 | 26358 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 1528075 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 26346 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
transactionid | | | | | | 2275983 | | | | 14/4861 | 25281 | ExclusiveLock | t
relation | 26166 | 27539 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27558 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27559 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
virtualxid | | | | | 6/144 | | | | | 6/144 | 17710 | ExclusiveLock | t
relation | 26166 | 27538 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27550 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27615 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27535 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26505 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27557 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26346 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 1528077 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 26265 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27537 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27545 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 1/5474 | 25639 | RowShareLock | t
relation | 26166 | 27538 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27615 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26295 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27557 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 1528074 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27549 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26373 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26385 | | | | | | | | 14/4861 | 25281 | RowExclusiveLock | t
relation | 26166 | 27617 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26295 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27547 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 1528074 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 1528076 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 27616 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27548 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27549 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 1528077 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26265 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27537 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26521 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27545 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 11564 | 10969 | | | | | | | | 5/136 | 25716 | AccessShareLock | t
relation | 26166 | 26229 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26373 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27617 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27550 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26497 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27535 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 28020 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26505 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27547 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 1528076 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 27616 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27548 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
transactionid | | | | | | 2275983 | | | | 1/5474 | 25639 | ShareLock | f
relation | 26166 | 27539 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27558 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27559 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26521 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26229 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 1528073 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 26559 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26553 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26379 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26361 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27587 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
tuple | 26166 | 26385 | 8 | 67 | | | | | | 6/144 | 17710 | ShareLock | t
relation | 26166 | 27543 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26557 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27536 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26507 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26259 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26491 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27563 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26241 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26241 | | | | | | | | 1/5474 | 25639 | RowShareLock | t
relation | 26166 | 27552 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26367 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26543 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27551 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27551 | | | | | | | | 14/4861 | 25281 | RowExclusiveLock | t
relation | 26166 | 26379 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26391 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27546 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
tuple | 26166 | 26385 | 8 | 67 | | | | | | 18/75 | 25636 | ShareLock | t
relation | 26166 | 26557 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27536 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26367 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26346 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
transactionid | | | | | | 2275983 | | | | 6/144 | 17710 | ShareLock | f
relation | 26166 | 27539 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26265 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27537 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27545 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27593 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27538 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26497 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27615 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26295 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27535 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26505 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 1528074 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 27616 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27549 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
transactionid | | | | | | 2275983 | | | | 18/75 | 25636 | ShareLock | f
relation | 26166 | 27539 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26265 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27537 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26521 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27545 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26229 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26373 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27617 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26497 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26295 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27535 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26505 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27547 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27557 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 1528074 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 1528076 | | | | | | | | 1/5474 | 25639 | RowExclusiveLock | t
relation | 26166 | 27548 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 27549 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
virtualxid | | | | | 14/4861 | | | | | 14/4861 | 25281 | ExclusiveLock | t
relation | 26166 | 27587 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 27543 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26557 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26241 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26241 | | | | | | | | 18/75 | 25636 | RowShareLock | t
relation | 26166 | 27552 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26367 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 1528073 | | | | | | | | 18/75 | 25636 | RowExclusiveLock | t
relation | 26166 | 26559 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26549 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26391 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27546 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27587 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
tuple | 26166 | 26385 | 8 | 67 | | | | | | 1/5474 | 25639 | ShareLock | t
relation | 26166 | 27543 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 27536 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 1528078 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26241 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26241 | | | | | | | | 6/144 | 17710 | RowShareLock | t
relation | 26166 | 27552 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
virtualxid | | | | | 1/5474 | | | | | 1/5474 | 25639 | ExclusiveLock | t
relation | 26166 | 1528073 | | | | | | | | 6/144 | 17710 | RowExclusiveLock | t
relation | 26166 | 26559 | | | | | | | | 6/144 | 17710 | AccessShareLock | t
relation | 26166 | 26379 | | | | | | | | 1/5474 | 25639 | AccessShareLock | t
relation | 26166 | 26555 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26551 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26523 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 26391 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 26358 | | | | | | | | 14/4861 | 25281 | AccessShareLock | t
relation | 26166 | 27546 | | | | | | | | 18/75 | 25636 | AccessShareLock | t
relation | 26166 | 1528075 | | | | | | | | 14/4861 | 25281 | AccessShareLock | tUn explain sur le select me donne ceci
sensordb1=# explain verbose select record0_.id as id13_, record0_.broadcast_id as broadcast4_13_, record0_.owner_id as owner5_13_, record0_.recorddate as recorddate13_, record0_.recordvalue as recordva3_13_, record0_.recordvar_id as recordvar6_13_, record0_.target_id as target7_13_ from snsrRecord record0_ where record0_.recordvar_id='52' and record0_.owner_id='465714329' and (record0_.recorddate between '2011-09-21 00:00:00' and '2011-09-22 00:00:00') order by record0_.recorddate asc
;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------
Index Scan using idx_record_recorddate on snsrrecord record0_ (cost=0.00..17.08 rows=1 width=53)
Output: id, broadcast_id, owner_id, recorddate, recordvalue, recordvar_id, target_id
Index Cond: ((recorddate >= '2011-09-21 00:00:00'::timestamp without time zone) AND (recorddate <= '2011-09-22 00:00:00'::timestamp without time zone))
Filter: ((recordvar_id = 52::bigint) AND (owner_id = 465714329::bigint))L'explain analyze est en cours....
Hors ligne
Bon, pour déchiffrer: voici un lock non accordé.
transactionid | | | | | | 2275983 | | | | 6/144 | 17710 | ShareLock | f
Ce qu'on en retire: la transaction du pid 17710 a demandé un verrou sur l'id de transaction 2275983. On trouve qui possède cet id de transaction avec cette ligne-ci:
transactionid | | | | | | 2275983 | | | | 14/4861 | 25281 | ExclusiveLock | t
Donc le pid 25281. Donc effectivement, l'ordre SQL de la session 17710 est en attente de la session 25281, qui effectivement fait un SELECT.
Par contre, je doute que la session, dans sa transaction courante, n'ait fait qu'un SELECT, à cause de ça :
relation | 26166 | 27551 | | | | | | | | 14/4861 | 25281 | RowExclusiveLock | t
=> Elle a un rowexclusive sur la relation 27751 (voir qui c'est par pg_class, par la colonne cachée oid). Elle a donc voulu effectuer un update sur un enregistrement de cette table.
Ce qui a donc du se passer:
La session 25281 a fait un update d'un enregistrement sur la table «27751». Puis elle s'est lancée sur son select (le select n'a pas l'air de faire de mise à jour, je ne vois pas d'appel de fonction, ni dans son code, ni dans son plan).
La session 17710 est ensuite allée faire un update, un select for update, un delete (sur le même enregistrement), et se retrouve donc en attente de savoir comment va se terminer la session 25281: suivant que la session commit ou rollback, elle ne doit évidemment pas se comporter de la même façon.
Les verrous d'enregistrement ne sont pas dans pg_locks (sauf très temporairement), mais dans les tables, dans Postgres. Ça rend pg_locks moins facile à interpréter, mais ça a plein d'avantages (comme pouvoir verrouiller des millions d'enregistrements sans être à court de verrou).
Marc.
Hors ligne
@Marc, tu conclus sur l'éxecution d'une autre instruction qu'un select à cause de l'acquisition d'un verrou RowExclusiveLock durant la même session ?
je tente de determiner la relation en interrogant le champ pg_class, une fois connecté sur la base....
Merci en tout cas
Hors ligne
oui, le row exclusive n'est acquis que quand des données sont modifiées dans une table. donc update, delete, insert. J'ai dit une connerie plus haut, ça ne peut pas être juste un select for update, le verrou aurait été row share. Et si c'est vraiment le select qui le fait, c'est qu'il appelle un bout de PL caché quelque part. Ce que je ne vois pas dans son code, ni dans le plan (dans le plan, ça aurait pu être dû à une règle de réécriture de requête).
Donc pour savoir qui est l'heureuse victime:
SELECT relname from pg_class where oid=27751
Marc.
Hors ligne
Plus exactement, il conclut que le SELECT fait partie d'une transaction et que, dans cette transaction, le SELECT est précédé d'au moins un UPDATE. Et je suis d'accord avec lui.
Guillaume.
Hors ligne
OK si je résume l'approche sur les comportements bloquants :
1 - A plus haut niveau, verifier les sessions en cours via ps
2 - Regarder la table pg_locks à la recherche de verrous non attribués
3 - Identifier la session ayant acquis le verrou et chercher d'éventuelles raisons de blocage au sein de la même transaction en se calant sur la colonne mode
4 - Identifier les éventuelles relations lockées durant la même session pour en déduire une ou plusieurs instructions bloquantes durant la transaction fonctionnelle
5 - faire évoluer le code (deux tx differentes, update après select) pour eliminer ce cas de blocage.
6 - Une fois les comportements bloquants éliminés -la transaction fonctionnelle peut-être longue, mais elle se termine (cf logs postgres avec log_min_duration)-, on peut se concentrer sur les optimisations des requêtes lentes à coup de explain et de refacto fonctionelle / positionnement d'index / évolution de configuration
Merci de m'apprendre à pêcher.
E.
Hors ligne
En fait, la première chose importante est classique sur toutes les bases de données: ne garder les verrous qu'aussi peu de temps que nécessaire. Toute mise à jour des données verrouille au moins un petit quelque chose 
Après, pour la démarche pour identifier un coupable, oui, elle est bonne. Il faut regarder les verrous qui sont en attente, qui ils attendent, et ce que ce "qui" peut bien être en train de faire. Si nécessaire, on peut trouver l'enregistrement sur lequel une session est bloquée, avec le contrib pgrowlocks (c'est bien sûr une extension en 9.1), mais ça impose un full scan de la table bloquée, ce qui peut être coûteux (pour aller justement consulter les verrous des enregistrements).
Pour ce qui est de localiser, lors d'un audit d'une appli, les causes de ralentissements, les verrous sont effectivement une bonne cible. On peut d'ailleurs assez facilement les repérer en activant log_lock_waits. Une fois qu'on a réduit (si c'est possible) les attentes dues aux verrous, on peut aussi optimiser les requêtes bien entendu. Mais il y a pas mal d'autres facteurs qui peuvent jouer sur des mauvaises performances: la machine, l'architecture, le paramétrage de l'OS, le paramétrage de l'instance, l'application elle même… etc…
Marc.
Hors ligne
Noté, Merci encore.
E.
Hors ligne
Pages : 1