Re: Momentary Delay

2015-06-08 12:30 GMT-03:00 Adrian Klaver <adrian(dot)klaver(at)aklaver(dot)com>:

> On 06/08/2015 07:59 AM, Anderson Valadares wrote:
>
>> 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.
>>
>
> I do not have an answer, but I do have a question. What does:
>
> "There is a job
> 2/2 seconds locks collection of information, running queries, etc"
>
> mean?
>
>
>
> 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
>>
>
>
> --
> Adrian Klaver
> adrian(dot)klaver(at)aklaver(dot)com
>

Adrian
forgiveness for my english the meant "Exists a job run every 2 seconds
capturing information of locks, long running queries, etc."

Anderson