Traqueur, problème de verrouillage passé
Enquêter a posteriori
Téléchargement du traqueur pour PostgreSQL 11, 12, 13, 14 et 15
Téléchargement du traqueur pour PostgreSQL 10
Téléchargement du traqueur pour PostgreSQL 9.6
Téléchargement du traqueur pour PostgreSQL 9.5
Téléchargement du traqueur pour PostgreSQL 9.4
Téléchargement du traqueur pour PostgreSQL 9.3
Journal des changements
Signalement de bugs via le forum
Licence identique à celle de PostgreSQL, open source type BSD
Dossier des versions
Le traqueur sintéresse aux sessions actives. Sur un problème de verrouillage, si vous lutilisez en interactif, il vous donnera les coupables que vous pourrez retrouver manuellement dans pg_stat_activity et pg_prepared_xacts.
Le cas est un peu plus complexe si le problème nest plus en cours. Le principe du traqueur est de ne sintéresser quaux sessions actives. Vous retrouverez donc les victimes mais, si les coupables nont pas été suffisamment actifs, alors il passeront à travers les mailles du filet.
Pallier cet inconvénient est lobjet dune nouvelle option -u introduite par la version 2.03.00 du traqueur qui peut être combinée avec loption -b (mode batch). Les informations sur les process et transactions préparées bloquant dautres sessions sont enregistrées à chaque collecte dans deux tables traqueur_bloqueurs_process et traqueur_bloqueurs_transactions.
Démonstration avec PostgreSQL 9.3 :
select version();
version
------------------------------------------------------------------------------------------------------------------
PostgreSQL 9.3.20 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 5.4.0-6ubuntu1~16.04.4) 5.4.0 20160609, 64-bit
(1 ligne)
-- le traqueur tourne en mode batch
nohup ./traqueur.sh -b L -u &
tail -f nohup.out
INFORMATION, pas d'options de connexions indiquees, utilisation de la base traqueur detectee ...
INFORMATION, connecte a la base traqueur
INFORMATION, version de PostgreSQL detectee : 90320
INFORMATION, preparation de la collecte ...
INFORMATION, execution de la collecte ...
-- session A
set application_name=appA;
SET
create table t1(c1 int);
CREATE TABLE
create table t2(c2 int);
CREATE TABLE
start transaction;
START TRANSACTION
insert into t1(c1) values(1);
INSERT 0 1
-- session B
set application_name=appB;
SET
start transaction;
START TRANSACTION
insert into t1(c1) values(2);
INSERT 0 1
prepare transaction 'patanok';
PREPARE TRANSACTION
-- session C
set application_name=appC;
SET
start transaction;
START TRANSACTION
insert into t2(c2) values(1);
INSERT 0 1
-- session D
set application_name=appD;
SET
start transaction;
START TRANSACTION
insert into t2(c2) values(2);
INSERT 0 1
prepare transaction 'nouka';
PREPARE TRANSACTION
-- session E
set application_name=appE;
SET
truncate table t1;
-- en attente !
-- session F
set application_name=appF;
SET
select * from t1;
-- en attente !
Le décor est planté, le process de la session dappA et la transaction préparée par appB bloquent la session de lapplication appE et indirectement celle de lapplication appF. Le process de lapplication appC et la transaction préparée par appD possèdent des verrous mais ne bloquent pour linstant personne.
Que dit le traqueur en interactif ?
./traqueur.sh
traqueur 2.03.00 - outil de diagnostic performance pour PostgreSQL 9.3 => 11
INFORMATION, pas d'options de connexions indiquees, utilisation de la base traqueur detectee ...
INFORMATION, connecte a la base traqueur
INFORMATION, version de PostgreSQL detectee : 90320
INFORMATION, preparation de la collecte ...
INFORMATION, execution de la collecte et presentation des resultats ...
busy_pc | distinct_exe | db | pid | pg_user | client_ip | application | query | blockers
---------+--------------+----------+-------+----------+-----------+-------------+-------------------------+-----------
100 | 1 / 50 | postgres | 14749 | postgres | | appe | truncate table t1; | {0,14513}
100 | 1 / 50 | postgres | 14810 | postgres | | appf | select * from t1; | {0,14513}
100 | 2 / 50 | traqueur | 14503 | postgres | | traqueur | execute traqueur_sleep; |
(3 lignes)
Nous trouvons ici nos 2 sessions appe et appf bloquées par un process (pid 14513) et une transaction préparée (0). 14513 nest pas actif donc il napparaît pas. Cependant, il est simple si le problème est en cours den savoir plus sur lui :
\x
Affichage étendu activé.
select * from pg_stat_activity where pid = 14513;
-[ RECORD 1 ]----+------------------------------
datid | 12068
datname | postgres
pid | 14513
usesysid | 10
usename | postgres
application_name | appa
client_addr |
client_hostname |
client_port | -1
backend_start | 2017-12-22 11:06:09.969932+01
xact_start | 2017-12-22 11:06:34.93202+01
query_start | 2017-12-22 11:06:42.989482+01
state_change | 2017-12-22 11:06:42.990221+01
waiting | f
state | idle in transaction
query | insert into t1(c1) values(1);
Supposons à présent que le problème ne soit PLUS en cours et que lon vous demande ce qui a bien pu se passer. Le traqueur tournant en mode batch va nous donner la réponse :
psql traqueur
set search_path=traqueur;
SET
\d
Liste des relations
Schéma | Nom | Type | Propriétaire
----------+---------------------------------+-------+--------------
traqueur | traqueur_bloqueurs_process | table | postgres
traqueur | traqueur_bloqueurs_transactions | table | postgres
traqueur | traqueur_sessions_actives | table | postgres
(3 lignes)
select dtcol, pid, application_name, blockers from traqueur_sessions_actives where dtcol between timestamp '2017-12-22 11:20:00' and timestamp '2017-12-22 11:21:00';
dtcol | pid | application_name | blockers
-------------------------------+-------+------------------+-----------
2017-12-22 11:20:08.020736+01 | 14749 | appe | {0,14513}
2017-12-22 11:20:08.020736+01 | 14810 | appf | {0,14513}
2017-12-22 11:20:18.032776+01 | 14749 | appe | {0,14513}
2017-12-22 11:20:18.032776+01 | 14810 | appf | {0,14513}
2017-12-22 11:20:28.040841+01 | 14749 | appe | {0,14513}
2017-12-22 11:20:28.040841+01 | 14810 | appf | {0,14513}
2017-12-22 11:20:38.053496+01 | 14749 | appe | {0,14513}
2017-12-22 11:20:38.053496+01 | 14810 | appf | {0,14513}
2017-12-22 11:20:48.066396+01 | 14749 | appe | {0,14513}
2017-12-22 11:20:48.066396+01 | 14810 | appf | {0,14513}
2017-12-22 11:20:58.079023+01 | 14749 | appe | {0,14513}
2017-12-22 11:20:58.079023+01 | 14810 | appf | {0,14513}
(12 lignes)
select distinct datname, pid, usename, application_name, state, query from traqueur_bloqueurs_process where dtcol between timestamp '2017-12-22 11:20:00' and timestamp '2017-12-22 11:21:00';
datname | pid | usename | application_name | state | query
----------+-------+----------+------------------+---------------------+-------------------------------
postgres | 14513 | postgres | appa | idle in transaction | insert into t1(c1) values(1);
(1 ligne)
select distinct transaction, gid, owner, database from traqueur_bloqueurs_transactions where dtcol between timestamp '2017-12-22 11:20:00' and timestamp '2017-12-22 11:21:00';
transaction | gid | owner | database
-------------+---------+----------+----------
496086 | patanok | postgres | postgres
(1 ligne)
Conclusion
Vous pouvez ainsi obtenir davantage dinformations sur les méchants bloqueurs finaux que les simples numéros de process.
Mise à jour : 22/12/2017