Vous n'êtes pas identifié(e).

#1 Re : Optimisation » Optimisation [suite] - lecture analyze » 22/11/2011 18:32:45

l'environnement est Xenifié (Infra Gandi). Je plonge dans l'article. Merci ruju

#2 Re : Optimisation » Optimisation [suite] - lecture analyze » 22/11/2011 16:15:47

rjuju a écrit :

Vous pouvez utiliser l'option buffers du explain comme montré au dessus pour voir si les différences viennent de la lecture en cache ou sur disque.

Avez-vous la dernière version de postgresql 8.4 ? (8.4.9)

Sinon, le changement de temps d'exécution se reproduit-il à chaque fois que vous lancez une requête qui porte sur des données qui ne se trouvent pas dans le cache ou cela reste-t-il exceptionnel ? (dans ce cas peut-être d'autres traitements bloquaient la requête).

Et pour finir si vous n'avez toujours pas de réponse, un peu plus d'informations sur la configuration matérielle de votre serveur (disque, processeur ...), s'il est dédié et quelques valeurs du postgresql.conf (shared_buffers ...) et le système d'exploitation pourraient peut-être nous donner d'autres indices.

Bonjour rjuju,

j'ai bien peur que la version de la version psql m'empeche l'emploi de l'instruction explain (analyze,buffers) dans l'explain plan, d'ou mon retour précedent. Le changement de temps d'excution n'est pas exceptionnel, j'ai du désactivé l'appel au code executant la requete pour retrouver de la fluidité au niveau navigation.

pour être performante, je dois utiliser le cache, mais pour exploiter le cache il faut passer par une premiere execution hyper longue pour une simple requête, avec une table de 700 000 enregistrements...

               Table "public.snsrbroadcast"
     Column     |            Type             | Modifiers 
----------------+-----------------------------+-----------
 id             | bigint                      | not null
 analysisdate   | timestamp without time zone | 
 analysisresult | character varying(255)      | 
 analysisstatus | character varying(255)      | 
 content        | bytea                       | 
 contentsize    | integer                     | 
 format         | character varying(255)      | 
 fullheader     | boolean                     | 
 receptiondate  | timestamp without time zone | 
 requestid      | character varying(255)      | 
 gateway_id     | bigint                      | 
Indexes:
    "snsrbroadcast_pkey" PRIMARY KEY, btree (id)
    "id_broadcast_result" btree (analysisresult)
    "id_broadcast_status" btree (analysisstatus)
    "idx_broadcast_analysisdate" btree (analysisdate)
    "idx_broadcast_gateway" btree (gateway_id)
    "idx_broadcast_gw_reception_date" btree (gateway_id, receptiondate)
    "idx_broadcast_receptiondate" btree (receptiondate)
Foreign-key constraints:
    "fk_broadcast_owner" FOREIGN KEY (gateway_id) REFERENCES snsrdevice(id)
Referenced by:
    TABLE "snsrexport" CONSTRAINT "fk_export_broadcast" FOREIGN KEY (broadcast_id) REFERENCES snsrbroadcast(id)
    TABLE "snsrrecord" CONSTRAINT "fk_record_broadcast" FOREIGN KEY (broadcast_id) REFERENCES snsrbroadcast(id)

la base 8.4.7-0  tourne sous Ubuntu 9.10  virtualisé 2.6.27-xenU-4265-i386 dont les caractéristiques hardware sont les suivantes :

cpu:                                                            
                       Intel(R) Xeon(R) CPU           L5520  @ 2.27GHz, 2260 MHz
                       Intel(R) Xeon(R) CPU           L5520  @ 2.27GHz, 2260 MHz

memory : 1024 mb

filesystem : ext3

disk : SAS raid10

côté postgresql.conf, voici les infos de conf modifiées par rapport aux valeurs par défaut

log_destination = 'syslog'              # Valid values are combinations of
                                        # stderr, csvlog, syslog and eventlog,
                                        # depending on platform.  csvlog
                                        # requires logging_collector to be on.
#redirect_stderr = off
silent_mode = on
log_min_duration_statement = 3000
shared_buffers = 128MB
effective_cache_size = 256MB

Merci en tout cas

#3 Re : Optimisation » Optimisation [suite] - lecture analyze » 22/11/2011 13:26:06

Après quelques jours de congés je reviens sur la question. je tourne en postresql 8.4, comment puis-je investiguer le coup des buffers ?

#5 Optimisation » Optimisation [suite] - lecture analyze » 22/10/2011 14:40:12

7uc0
Réponses : 8

Bonjour la communauté,
En cours d'optimisation sur une requête, l'instruction suivante me laisse perplexe : executée une seule fois, son temps d'execution est long, executée à nouveau, le temps d'execution descend nettement.

explain analyze select count(*) as col_0_0_ from snsrBroadcast broadcast0_ where broadcast0_.gateway_id='52910199' limit 2

resultat #1

                                                              QUERY PLAN                                                                    
--------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=816.50..816.51 rows=1 width=0) (actual time=4463.501..4463.504 rows=1 loops=1)
   ->  Aggregate  (cost=816.50..816.51 rows=1 width=0) (actual time=4463.496..4463.497 rows=1 loops=1)
         ->  Bitmap Heap Scan on snsrbroadcast broadcast0_  (cost=6.00..815.96 rows=213 width=0) (actual time=376.240..4463.001 rows=309 loops=1)
               Recheck Cond: (gateway_id = 52910199::bigint)
               ->  Bitmap Index Scan on idx_broadcast_gateway  (cost=0.00..5.94 rows=213 width=0) (actual time=376.175..376.175 rows=309 loops=1)
                     Index Cond: (gateway_id = 52910199::bigint)
 Total runtime: 4464.248 ms
(7 rows)

Executée une seconde fois, voici le résultat

                                                                  QUERY PLAN                                                                  
----------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=816.50..816.51 rows=1 width=0) (actual time=0.965..0.967 rows=1 loops=1)
   ->  Aggregate  (cost=816.50..816.51 rows=1 width=0) (actual time=0.962..0.963 rows=1 loops=1)
         ->  Bitmap Heap Scan on snsrbroadcast broadcast0_  (cost=6.00..815.96 rows=213 width=0) (actual time=0.159..0.771 rows=309 loops=1)
               Recheck Cond: (gateway_id = 52910199::bigint)
               ->  Bitmap Index Scan on idx_broadcast_gateway  (cost=0.00..5.94 rows=213 width=0) (actual time=0.100..0.100 rows=309 loops=1)
                     Index Cond: (gateway_id = 52910199::bigint)
 Total runtime: 1.015 ms
(7 rows)

Existe-t-il un "cache" de requêtes evitant au moteur les mêmes opérations que pour #1 ?

E.

#6 Re : Optimisation » Optimisation [Suite] - Impact order by » 04/10/2011 12:00:11

Merci pour ce temps de réponse qui me permet de réduire le temps de réponse !

#7 Optimisation » Optimisation [Suite] - Impact order by » 04/10/2011 10:57:43

7uc0
Réponses : 2

Bonjour,

je poursuis la série des best practices pour tenter de mieux comprende le fonctionnement du moteur sur des cas d'ordonnancement. Je m'explique:
la requête suivante  porte sur une table d'à peu près (500.0000 enregistrements), le temps de réponse sans order by est "normal"

explain analyze select broadcast0_.id as id40_ from snsrbroadcast as broadcast0_ where broadcast0_.gateway_id=61172076 limit 20;

QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..76.16 rows=20 width=8) (actual time=0.050..0.234 rows=20 loops=1)
   ->  Index Scan using idx_broadcast_gateway on snsrbroadcast broadcast0_  (cost=0.00..11192.09 rows=2939 width=8) (actual time=0.049..0.209 rows=20 loops=1)
         Index Cond: (gateway_id = 61172076)
 Total runtime: 0.270 ms
(4 rows)

En revanche, l'ajout d'une contrainte d'ordonnancement rend l'execution beaucoup plus longue.

explain analyze select broadcast0_.id as id40_ from snsrbroadcast as broadcast0_ where broadcast0_.gateway_id=61172076 order by broadcast0_.receptiondate desc limit 20;
                                                                                       QUERY PLAN                                                                                        
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..593.77 rows=20 width=16) (actual time=106120.505..106131.201 rows=20 loops=1)
   ->  Index Scan Backward using idx_broadcast_receptiondate on snsrbroadcast broadcast0_  (cost=0.00..87254.69 rows=2939 width=16) (actual time=106120.502..106131.169 rows=20 loops=1)
         Filter: (gateway_id = 61172076)
 Total runtime: 106131.253 ms

Ce qui me surprend encore plus, c'est que la bascule en asc conduit à un temps plus long que la requête initiale, mais négligeable par rapport à l'execution en desc

explain analyze select broadcast0_.id as id40_ from snsrbroadcast as broadcast0_ where broadcast0_.gateway_id=61172076 order by broadcast0_.receptiondate asc limit 20;
                                                                                QUERY PLAN                                                                                 
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..593.77 rows=20 width=16) (actual time=631.043..1650.628 rows=20 loops=1)
   ->  Index Scan using idx_broadcast_receptiondate on snsrbroadcast broadcast0_  (cost=0.00..87254.69 rows=2939 width=16) (actual time=631.041..1650.586 rows=20 loops=1)
         Filter: (gateway_id = 61172076)
 Total runtime: 1650.688 ms

Quelque chose m'échappe sur le comportement du moteur, d'ou ce post. Ah, j'oubliais les caractéristique de la table sollicitée :

               Table "public.snsrbroadcast"
     Column     |            Type             | Modifiers 
----------------+-----------------------------+-----------
 id             | bigint                      | not null
 analysisdate   | timestamp without time zone | 
 analysisresult | character varying(255)      | 
 analysisstatus | character varying(255)      | 
 content        | bytea                       | 
 contentsize    | integer                     | 
 format         | character varying(255)      | 
 fullheader     | boolean                     | 
 receptiondate  | timestamp without time zone | 
 requestid      | character varying(255)      | 
 gateway_id     | bigint                      | 
Indexes:
    "snsrbroadcast_pkey" PRIMARY KEY, btree (id)
    "id_broadcast_result" btree (analysisresult)
    "id_broadcast_status" btree (analysisstatus)
    "idx_broadcast_analysisdate" btree (analysisdate)
    "idx_broadcast_gateway" btree (gateway_id)
    "idx_broadcast_receptiondate" btree (receptiondate)
Foreign-key constraints:
    "fk_broadcast_owner" FOREIGN KEY (gateway_id) REFERENCES snsrdevice(id)
Referenced by:
    TABLE "snsrexport" CONSTRAINT "fk_export_broadcast" FOREIGN KEY (broadcast_id) REFERENCES snsrbroadcast(id)
    TABLE "snsrrecord" CONSTRAINT "fk_record_broadcast" FOREIGN KEY (broadcast_id) REFERENCES snsrbroadcast(id)

-E.

#9 Re : Optimisation » Investigation [suite] - Temps d'execution » 23/09/2011 11:03:54

Effectivementn, du Bitmap Heap et Bitmap Index (sans index, j'aurais eu droit à du Full / Seq  scan ?)

explain analyze select count(*) from snsrrecord where recorddate between '2011-09-22 00:00:00' and '2011-09-23 00:00:00';
                                                                              QUERY PLAN                                                                               
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=486244.42..486244.43 rows=1 width=0) (actual time=111493.738..111493.739 rows=1 loops=1)
   ->  Bitmap Heap Scan on snsrrecord  (cost=8645.59..485492.17 rows=300897 width=0) (actual time=44681.949..110085.654 rows=2190730 loops=1)
         Recheck Cond: ((recorddate >= '2011-09-22 00:00:00'::timestamp without time zone) AND (recorddate <= '2011-09-23 00:00:00'::timestamp without time zone))
         ->  Bitmap Index Scan on idx_record_recorddate  (cost=0.00..8570.36 rows=300897 width=0) (actual time=44650.388..44650.388 rows=2221609 loops=1)
               Index Cond: ((recorddate >= '2011-09-22 00:00:00'::timestamp without time zone) AND (recorddate <= '2011-09-23 00:00:00'::timestamp without time zone))
 Total runtime: 111495.077 ms

Je rebondis sur un de tes posts précedents pour creuser :

"On pourrait déjà commencer par passer les stats sur les tables. Elles ne sont pas à jour du tout"

Que signifie le terme stats ? l'execution d'anlyze ? vacuum ? les deux ? pas du tout

#10 Re : Optimisation » Investigation [suite] - Temps d'execution » 23/09/2011 10:42:07

Le statut des traitements automatisés

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
 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 |                  | 22-09-2011 18:09 | 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 | 23-09-2011 01:00 | 22-09-2011 18:09 | 23-09-2011 00:46
 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 | 22-09-2011 01:52
 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 | 22-09-2011 17:52 | 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 |                  | 22-09-2011 18:09 | 
 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 |

#11 Re : Optimisation » Investigation [suite] - Temps d'execution » 23/09/2011 10:36:59

@Marc : FS Au taquet durant l'execution de la requete avant analyze, CPU au taquet durant analyze

L'analyse réduit considérablement le temps de requête, N'y a-t-il pas un démon similaire à l'autovacuum, chargé d'orchestrer les analyses sur une base ?

Merci en tout cas

#12 Optimisation » Investigation [suite] - Temps d'execution » 22/09/2011 17:34:02

7uc0
Réponses : 12

[RE] bonjour,

Dans la continuité de mes investigations sur des comportements lents et / ou bloquants, j'observe des temps de réponses hyper longs  (plusieurs minutes) sur une requête suivante contre une table assez volumineuse (entre 50 et 60 M d'enregistrements au total) :

explain analyze select count(*) from snsrrecord where recorddate between '2011-09-21 00:00:00' and '2011-09-23 00:00:00';
                                                                           QUERY PLAN                                                                            
-----------------------------------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=17.10..17.11 rows=1 width=0) (actual time=268580.842..268580.843 rows=1 loops=1)
   ->  Index Scan using idx_record_recorddate on snsrrecord  (cost=0.00..17.10 rows=1 width=0) (actual time=45.583..267006.647 rows=2389648 loops=1)
         Index Cond: ((recorddate >= '2011-09-21 00:00:00'::timestamp without time zone) AND (recorddate <= '2011-09-23 00:00:00'::timestamp without time zone))
 Total runtime: 268580.889 ms
(4 rows)

  count  
---------
 2387745
explain analyze select count(*) from snsrrecord where recorddate between '2011-09-22 00:00:00' and '2011-09-23 00:00:00';
                                                                           QUERY PLAN                                                                            
-----------------------------------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=17.10..17.11 rows=1 width=0) (actual time=15314.732..15314.733 rows=1 loops=1)
   ->  Index Scan using idx_record_recorddate on snsrrecord  (cost=0.00..17.10 rows=1 width=0) (actual time=23.264..15218.793 rows=153268 loops=1)
         Index Cond: ((recorddate >= '2011-09-22 00:00:00'::timestamp without time zone) AND (recorddate <= '2011-09-23 00:00:00'::timestamp without time zone))
 Total runtime: 15314.781 ms

 count  
--------
 151326

La machine n'est pas "au taquet"

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                                                                      
 1541 postgres  20   0 50640  37m  35m D    1  3.7   0:28.32 postgres

J'aimerais trouver le moyen de réduire significativement ce temps, mais j'avoue ne pas savoir quel levier activer (réduire le nombre d'enregistrements ?)

E.

PG 8.4.7, ubuntu 9.10

#14 Re : Optimisation » Investigation :: Bonnes pratiques » 22/09/2011 15:09:51

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.

#15 Re : Optimisation » Investigation :: Bonnes pratiques » 22/09/2011 14:45:35

@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

#16 Re : Optimisation » Investigation :: Bonnes pratiques » 22/09/2011 11:56:03

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  | t

Un 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....

#17 Re : Optimisation » Investigation :: Bonnes pratiques » 22/09/2011 11:17:55

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+00

les 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 asc

Et

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   |       60068

Mon 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

#18 Re : Optimisation » Investigation :: Bonnes pratiques » 21/09/2011 17:40:45

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) SELECT

J'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 postgres

Voici 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.

#19 Optimisation » Investigation :: Bonnes pratiques » 21/09/2011 16:05:55

7uc0
Réponses : 14

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.

Pied de page des forums

Propulsé par FluxBB