Momentary Delay

Hi
We are experiencing an intermittent problem in a GIS database from a
client. Some times of the day is as if the PostgreSQL executed the slowest
operations see below an example. The query was performed three times, twice
I canceled and the third time I left it to end. The consultation took 10
seconds to finish, but the measured execution time is 20 ms. As we have
several queries that run every 2 seconds when this momentary delay occurs
queries accumulate and burst the limit of 203 connections allowed. The
interval of "momentary stop" are approximately 2 seconds occurring at
random times and during these stoppages occur no locks and no increased
load on the server is identified. There is a job 2/2 seconds locks
collection of information, running queries, etc., nmon also collects
information every 2 seconds. My client asks what causes these momentary
stops? because it affects all operations of the database? etc. How do I
identify what is causing these delays in executions of operations in the
database?

The Server is a IBM P720 128G RAM PostgreSQL 9.2.9 on
powerpc-ibm-aix7.1.0.0, compiled by gcc (GCC) 4.6.4, 64-bit

Evolution of the number of connections for a period

snap_datetime | #connections
----------------------------------------------+-------------
2015-06-05 09:25:00.954731-03 | 74
2015-06-05 09:26:00.249187-03 | 205
2015-06-05 09:27:00.826874-03 | 207
2015-06-05 09:28:00.374666-03 | 73
2015-06-05 09:29:00.690696-03 | 75

Occurrence of the problem

citgis=# select max(dvi_sub.dvi_cod_dados_via_iti) as dvi_cod_dados_via_iti,
dvi_sub.via_cod_viagem
from gis_dvi_dados_viagem_itinerario dvi_sub, gis_via_viagem
via_sub, gis_iti_itinerario iti_sub
where dvi_sub.via_cod_viagem = via_sub.via_cod_viagem
and via_sub.via_status_viagem = 'A'
and via_sub.via_dt_hora_ini > now() - interval '9 hours'
and iti_sub.lin_cod_linha = 389
and iti_sub.iti_sentido_itinerario = 'I'
and iti_sub.iti_cod_itinerario_linha =
via_sub.iti_cod_itinerario_linha
and dvi_sub.vlo_cod_localizacao is not null
group by dvi_sub.via_cod_viagem,
iti_sub.iti_cod_itinerario_linha, via_sub.equ_cod_eqpto
;
Cancel request sent
ERROR: canceling statement due to user request
Time: 2555.557 ms
citgis=# select max(dvi_sub.dvi_cod_dados_via_iti) as dvi_cod_dados_via_iti,
dvi_sub.via_cod_viagem
from gis_dvi_dados_viagem_itinerario dvi_sub, gis_via_viagem
via_sub, gis_iti_itinerario iti_sub
where dvi_sub.via_cod_viagem = via_sub.via_cod_viagem
and via_sub.via_status_viagem = 'A'
and via_sub.via_dt_hora_ini > now() - interval '9 hours'
and iti_sub.lin_cod_linha = 389
and iti_sub.iti_sentido_itinerario = 'I'
and iti_sub.iti_cod_itinerario_linha =
via_sub.iti_cod_itinerario_linha
and dvi_sub.vlo_cod_localizacao is not null
group by dvi_sub.via_cod_viagem,
iti_sub.iti_cod_itinerario_linha, via_sub.equ_cod_eqpto
;
Cancel request sent
ERROR: canceling statement due to user request
Time: 2192.572 ms
citgis=# explain analyze select max(dvi_sub.dvi_cod_dados_via_iti) as
dvi_cod_dados_via_iti,
dvi_sub.via_cod_viagem
from gis_dvi_dados_viagem_itinerario dvi_sub, gis_via_viagem
via_sub, gis_iti_itinerario iti_sub
where dvi_sub.via_cod_viagem = via_sub.via_cod_viagem
and via_sub.via_status_viagem = 'A'
and via_sub.via_dt_hora_ini > now() - interval '9 hours'
and iti_sub.lin_cod_linha = 389
and iti_sub.iti_sentido_itinerario = 'I'
and iti_sub.iti_cod_itinerario_linha =
via_sub.iti_cod_itinerario_linha
and dvi_sub.vlo_cod_localizacao is not null
group by dvi_sub.via_cod_viagem,
iti_sub.iti_cod_itinerario_linha, via_sub.equ_cod_eqpto
;
Cancel request sent
ERROR: canceling statement due to user request
Time: 10164.015 ms
citgis=# select now();
now
-------------------------------
2015-06-05 09:27:22.006072-03
(1 row)

Time: 0.152 ms
citgis=# select max(dvi_sub.dvi_cod_dados_via_iti) as dvi_cod_dados_via_iti,
dvi_sub.via_cod_viagem
from gis_dvi_dados_viagem_itinerario dvi_sub, gis_via_viagem
via_sub, gis_iti_itinerario iti_sub
where dvi_sub.via_cod_viagem = via_sub.via_cod_viagem
and via_sub.via_status_viagem = 'A'
and via_sub.via_dt_hora_ini > now() - interval '9 hours'
and iti_sub.lin_cod_linha = 389
and iti_sub.iti_sentido_itinerario = 'I'
and iti_sub.iti_cod_itinerario_linha =
via_sub.iti_cod_itinerario_linha
and dvi_sub.vlo_cod_localizacao is not null
group by dvi_sub.via_cod_viagem,
iti_sub.iti_cod_itinerario_linha, via_sub.equ_cod_eqpto
;
dvi_cod_dados_via_iti | via_cod_viagem
-----------------------+----------------
1059964443 | 7989813
1060072723 | 7990876
(2 rows)

Time: 5565.175 ms
citgis=# select max(dvi_sub.dvi_cod_dados_via_iti) as dvi_cod_dados_via_iti,
dvi_sub.via_cod_viagem
from gis_dvi_dados_viagem_itinerario dvi_sub, gis_via_viagem
via_sub, gis_iti_itinerario iti_sub
where dvi_sub.via_cod_viagem = via_sub.via_cod_viagem
and via_sub.via_status_viagem = 'A'
and via_sub.via_dt_hora_ini > now() - interval '9 hours'
and iti_sub.lin_cod_linha = 389
and iti_sub.iti_sentido_itinerario = 'I'
and iti_sub.iti_cod_itinerario_linha =
via_sub.iti_cod_itinerario_linha
and dvi_sub.vlo_cod_localizacao is not null
group by dvi_sub.via_cod_viagem,
iti_sub.iti_cod_itinerario_linha, via_sub.equ_cod_eqpto
;
dvi_cod_dados_via_iti | via_cod_viagem
-----------------------+----------------
1059964445 | 7989813
1060072725 | 7990876
(2 rows)

Time: 27.944 ms
citgis=# select max(dvi_sub.dvi_cod_dados_via_iti) as dvi_cod_dados_via_iti,
dvi_sub.via_cod_viagem
from gis_dvi_dados_viagem_itinerario dvi_sub, gis_via_viagem
via_sub, gis_iti_itinerario iti_sub
where dvi_sub.via_cod_viagem = via_sub.via_cod_viagem
and via_sub.via_status_viagem = 'A'
and via_sub.via_dt_hora_ini > now() - interval '9 hours'
and iti_sub.lin_cod_linha = 389
and iti_sub.iti_sentido_itinerario = 'I'
and iti_sub.iti_cod_itinerario_linha =
via_sub.iti_cod_itinerario_linha
and dvi_sub.vlo_cod_localizacao is not null
group by dvi_sub.via_cod_viagem,
iti_sub.iti_cod_itinerario_linha, via_sub.equ_cod_eqpto
;
dvi_cod_dados_via_iti | via_cod_viagem
-----------------------+----------------
1059964445 | 7989813
1060072727 | 7990876
(2 rows)

Time: 24.428 ms

Greetings

Anderson