pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
SQL Perfomance during autovacuum
3+ messages / 3 participants
[nested] [flat]

* SQL Perfomance during autovacuum
@ 2018-12-19 06:04 anand086 <anand086@gmail.com>
  2018-12-19 06:33 ` Re: SQL Perfomance during autovacuum David Rowley <david.rowley@2ndquadrant.com>
  2018-12-22 00:13 ` Re: SQL Perfomance during autovacuum Jeff Janes <jeff.janes@gmail.com>
  0 siblings, 2 replies; 3+ messages in thread

From: anand086 @ 2018-12-19 06:04 UTC (permalink / raw)
  To: pgsql-performance

Hi All,

I am looking into a performance issue and needed your input and thoughts.

We have table (non-partitioned) of 500Gb with 11 indexes 

+--------------+---------------+--------------+-------------+--------------+---------+--------+------------+--------+

| row_estimate |  total_bytes  | index_bytes  | toast_bytes | table_bytes  | 
total  | index  |   toast    | table  |

+--------------+---------------+--------------+-------------+--------------+---------+--------+------------+--------+

|  1.28611e+09 | 1400081645568 | 858281418752 |        8192 | 541800218624 |
1304 GB | 799 GB | 8192 bytes | 505 GB |

+--------------+---------------+--------------+-------------+--------------+---------+--------+------------+--------+


Application runs a simple sql ,

select distinct testtbl_.id as col_0_0_ from demo.test_table testtbl_ where
testtbl_.entity_id='10001' and testtbl_.last_updated>=to_date('22-10-2018',
'dd-MM-yyyy') and testtbl_.last_updated<to_date('23-10-2018', 'dd-MM-yyyy')
and testtbl_.quantity_available>0 and testtbl_.src_name='distribute_item'
and (testtbl_.item not like 'SHIP%') order by testtbl_.id limit 10000;

The Execution time for the above sql is  17841.467 ms during normal
operations but when autovacuum runs on table test_table, the same sql took
1628495.850 ms (from the postgres log). 

We have noticed this increase in execution times for the sqls only when
autovacuum runs and it runs with prevent wraparound mode. I think during the
autovacuum process the Buffers: shared hit are increasing causing increase
in execution time.

I need help with the approach to debug this issue. Is this expected
behaviour wherein sql execution timing incease during the autovacuum? If so
, what is the reason for the same? 




--
Sent from: http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html




^ permalink  raw  reply  [nested|flat] 3+ messages in thread

* Re: SQL Perfomance during autovacuum
  2018-12-19 06:04 SQL Perfomance during autovacuum anand086 <anand086@gmail.com>
@ 2018-12-19 06:33 ` David Rowley <david.rowley@2ndquadrant.com>
  1 sibling, 0 replies; 3+ messages in thread

From: David Rowley @ 2018-12-19 06:33 UTC (permalink / raw)
  To: anand086 <anand086@gmail.com>; +Cc: pgsql-performance

On Wed, 19 Dec 2018 at 19:04, anand086 <anand086@gmail.com> wrote:
> We have noticed this increase in execution times for the sqls only when
> autovacuum runs and it runs with prevent wraparound mode. I think during the
> autovacuum process the Buffers: shared hit are increasing causing increase
> in execution time.
>
> I need help with the approach to debug this issue. Is this expected
> behaviour wherein sql execution timing incease during the autovacuum? If so
> , what is the reason for the same?

This is unsurprising. There are various GUC settings designed to
throttle vacuum to help minimise this problem. The auto-vacuum process
is competing for the same resources as your query is, and is likely
loading many new buffers, therefore flushing buffers out of cache that
might be useful for your query.

Showing the output of:

select name,setting from pg_Settings where name like '%vacuum%';

may be of use here.

You'll particularly want to pay attention to the settings of
autovacuum_vacuum_cost_delay, autovacuum_vacuum_cost_limit and
vacuum_cost_limit.  The settings of vacuum_cost_page_dirty,
vacuum_cost_page_hit, vacuum_cost_page_miss matter too, but these are
less often changed by users.

You may be able to learn exactly what's going on with the query by doing:

set track_io_timing = on;
explain (analyze, buffers, timing) <your query here>

both during the auto-vacuum run, and at a time when it's not running.

If the query plans of each match, then pay attention to the number of
buffers read and how long they took to read. If you find that these
don't explain the variation then something else is at fault, perhaps
CPU contention, or perhaps swapping due to high memory usage.

It also seems pretty strange that you should need to use DISTINCT on a
column that's named "id".

-- 
 David Rowley                   http://www.2ndQuadrant.com/
 PostgreSQL Development, 24x7 Support, Training & Services




^ permalink  raw  reply  [nested|flat] 3+ messages in thread

* Re: SQL Perfomance during autovacuum
  2018-12-19 06:04 SQL Perfomance during autovacuum anand086 <anand086@gmail.com>
@ 2018-12-22 00:13 ` Jeff Janes <jeff.janes@gmail.com>
  1 sibling, 0 replies; 3+ messages in thread

From: Jeff Janes @ 2018-12-22 00:13 UTC (permalink / raw)
  To: anand086 <anand086@gmail.com>; +Cc: pgsql-performance

On Wed, Dec 19, 2018 at 1:04 AM anand086 <anand086@gmail.com> wrote:

>
> The Execution time for the above sql is  17841.467 ms during normal
> operations but when autovacuum runs on table test_table, the same sql took
> 1628495.850 ms (from the postgres log).
>
> We have noticed this increase in execution times for the sqls only when
> autovacuum runs and it runs with prevent wraparound mode.


Some competition for resource is to be expected with autovacuum, but making
a one-hundred fold difference in run time is rather extreme. I'd suggest
that what you have is a locking issue.  Something is trying to take a brief
Access Exclusive lock on the table.  It blocks on the lock held by the
autovacuum, and then the Access Share lock needed for your query blocks
behind that.

Normally an autovacuum will yield the lock when it notices it is blocking
something else, but will not do so for wraparound.

If you have log_lock_waits turned on, you should see some evidence in the
log file if this is the case.

Cheers,

Jeff

^ permalink  raw  reply  [nested|flat] 3+ messages in thread


end of thread, other threads:[~2018-12-22 00:13 UTC | newest]

Thread overview: 3+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2018-12-19 06:04 SQL Perfomance during autovacuum anand086 <anand086@gmail.com>
2018-12-19 06:33 ` David Rowley <david.rowley@2ndquadrant.com>
2018-12-22 00:13 ` Jeff Janes <jeff.janes@gmail.com>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox