Re: First query on each connection is too slow

Поиск
Список
Период
Сортировка
От Pavan Teja
Тема Re: First query on each connection is too slow
Дата
Msg-id CACh9nsZ+RoGG0pO9ZdoTEX7jjYcrQSA7vViTMSAZROV2ycb9ww@mail.gmail.com
обсуждение исходный текст
Ответ на First query on each connection is too slow  (Vadim Nevorotin <nevorotin@gmail.com>)
Ответы Re: First query on each connection is too slow
Re: First query on each connection is too slow
Список pgsql-general
Hi Vadim,

Too much of shared buffers allocation also causes problem. Read the documentation.


Regards,
Pavan

On Wed, Jun 13, 2018, 3:23 PM Vadim Nevorotin <nevorotin@gmail.com> wrote:
I have a very strange problem. I'm using PostgreSQL 9.6 with PostGIS 2.3 (both from Debian Strecth repos) to store DB for OSM server (but actually it doesn't matter). And I've noticed, that on each new connection to DB first query is much slower (10x) than all others. E.g.:

$ psql test_gis
psql (9.6.7)
Type "help" for help.
test_gis=# \timing
Timing is on.
test_gis=# SELECT srid FROM geometry_columns WHERE f_table_name='planet_osm_polygon' AND f_geometry_column='way';
 srid
------
 3857
(1 row)
Time: 52.889 ms
test_gis=# SELECT srid FROM geometry_columns WHERE f_table_name='planet_osm_polygon' AND f_geometry_column='way';
 srid
------
 3857
(1 row)
Time: 2.070 ms
test_gis=#

If I run others instances of psql in parallel, when the first is active - they has absolutely the same problem. In one instance of psql query is fast (if it's not the first query), in others - first query is slow, but all others is fast.

EXPLAIN (ANALYZE, BUFFERS) for the first query shows very strange timings:
                                                                                      QUERY PLAN

--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

 Nested Loop Left Join  (cost=0.82..26.41 rows=1 width=4) (actual time=49.290..49.297 rows=1 loops=1)
   Join Filter: ((s_2.connamespace = n.oid) AND (s_2.conrelid = c.oid) AND (a.attnum = ANY (s_2.conkey)))
   Buffers: shared hit=18
   ->  Nested Loop Left Join  (cost=0.82..25.28 rows=1 width=14) (actual time=0.135..0.141 rows=1 loops=1)
         Join Filter: ((s_1.connamespace = n.oid) AND (s_1.conrelid = c.oid) AND (a.attnum = ANY (s_1.conkey)))
         Buffers: shared hit=17
         ->  Nested Loop Left Join  (cost=0.82..24.16 rows=1 width=14) (actual time=0.126..0.132 rows=1 loops=1)
               Join Filter: ((s.connamespace = n.oid) AND (s.conrelid = c.oid) AND (a.attnum = ANY (s.conkey)))
               Buffers: shared hit=16
               ->  Nested Loop  (cost=0.82..23.05 rows=1 width=14) (actual time=0.083..0.089 rows=1 loops=1)
                     Buffers: shared hit=15
                     ->  Nested Loop  (cost=0.55..17.75 rows=1 width=18) (actual time=0.078..0.082 rows=1 loops=1)
                           Join Filter: (c.relnamespace = n.oid)
                           Rows Removed by Join Filter: 5
                           Buffers: shared hit=12
                           ->  Nested Loop  (cost=0.55..16.61 rows=1 width=18) (actual time=0.072..0.074 rows=1 loops=1)
                                 Buffers: shared hit=11
                                 ->  Index Scan using pg_class_relname_nsp_index on pg_class c  (cost=0.27..8.30 rows=1 width=8) (actual time=0.049..0.050 rows=1 loops=1)
                                       Index Cond: (relname = 'planet_osm_polygon'::name)
                                       Filter: ((NOT pg_is_other_temp_schema(relnamespace)) AND has_table_privilege(oid, 'SELECT'::text) AND (relkind = ANY ('{r,v,m,f}'::"char"[])))
                                       Buffers: shared hit=8
                                 ->  Index Scan using pg_attribute_relid_attnam_index on pg_attribute a  (cost=0.28..8.30 rows=1 width=14) (actual time=0.021..0.021 rows=1 loops=1)
                                       Index Cond: ((attrelid = c.oid) AND (attname = 'way'::name))
                                       Filter: (NOT attisdropped)
                                       Buffers: shared hit=3
                           ->  Seq Scan on pg_namespace n  (cost=0.00..1.06 rows=6 width=4) (actual time=0.003..0.004 rows=6 loops=1)
                                 Buffers: shared hit=1
                     ->  Index Scan using pg_type_oid_index on pg_type t  (cost=0.27..5.29 rows=1 width=4) (actual time=0.005..0.007 rows=1 loops=1)
                           Index Cond: (oid = a.atttypid)
                           Filter: (typname = 'geometry'::name)
                           Buffers: shared hit=3
               ->  Seq Scan on pg_constraint s  (cost=0.00..1.09 rows=1 width=31) (actual time=0.041..0.041 rows=0 loops=1)
                     Filter: (consrc ~~* '%geometrytype(% = %'::text)
                     Rows Removed by Filter: 7
                     Buffers: shared hit=1
         ->  Seq Scan on pg_constraint s_1  (cost=0.00..1.09 rows=1 width=31) (actual time=0.009..0.009 rows=0 loops=1)
               Filter: (consrc ~~* '%ndims(% = %'::text)
               Rows Removed by Filter: 7
               Buffers: shared hit=1
   ->  Seq Scan on pg_constraint s_2  (cost=0.00..1.09 rows=1 width=77) (actual time=0.011..0.011 rows=0 loops=1)
         Filter: (consrc ~~* '%srid(% = %'::text)
         Rows Removed by Filter: 7
         Buffers: shared hit=1
 Planning time: 2.589 ms
 Execution time: 49.467 ms


(45 rows)

The same problem is when connecting to PostgreSQL from Mapnik, so it's not a psql problem. We have a lot of memory (shared_buffers = 20GB,  work_mem = 100MB) and a very small db (we've upload to empty db data only for one very small county). So I'm absolutely sure that it's the problem of main PostgreSQL.

And there are two questions: why this problem occurs and how can I fix it?

В списке pgsql-general по дате отправления:

Предыдущее
От: Vadim Nevorotin
Дата:
Сообщение: First query on each connection is too slow
Следующее
От: Maksim Milyutin
Дата:
Сообщение: Re: First query on each connection is too slow