Slow performance after restoring a dump

Поиск
Список
Период
Сортировка
От David Osborne
Тема Slow performance after restoring a dump
Дата
Msg-id CAKmpXCfZUyTwOT3m0HF+uAGbjHt9GHHvhP4jty6QJQLU4Ag8Dw@mail.gmail.com
обсуждение исходный текст
Ответы Re: Slow performance after restoring a dump  (Tom Lane <tgl@sss.pgh.pa.us>)
Список pgsql-performance
 
Hi, I was wondering if someone could help us work out why this query is so slow.

We've just dumped a database (Postgresql 9.1) and restored it to a new instance (AWS RDS 9.6) (via pg_dump, restored to psql)

We immediately see that the following fairly straightforward query is now extremely slow with a huge number of shared buffers hit.
On the new instance it takes 25 seconds. On the original system, 0.05 seconds.

The database schemas are both the same (with the same columns indexed) so I'm guessing it must be a configuration issue to make the planner go down a different route.
I have run an analyse on the whole database since restoring.

Also, if on the new instance, I disable indexscans, the query will take 0.047 seconds.

Can someone point us in the right direction on what's going on here?


Query:

explain (buffers,analyse)  select
            trans_date
            from stock_trans s
            join account_trans a using(account_trans_id)
            where product_id=100
            and credit_stock_account_id=3
            order by trans_date desc
            limit 1;


Bad Performance on New Instance:



                                                                                    QUERY PLAN          
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.87..9086.72 rows=1 width=4) (actual time=25829.287..25829.287 rows=0 loops=1)
   Buffers: shared hit=43944066
   ->  Nested Loop  (cost=0.87..6196547.28 rows=682 width=4) (actual time=25829.286..25829.286 rows=0 loops=1)
         Buffers: shared hit=43944066
         ->  Index Scan Backward using account_trans_date_idx on account_trans a  (cost=0.43..392996.60 rows=11455133 width=8) (actual time=0.007..3401.027 rows=11455133 loops=1)
               Buffers: shared hit=251082
         ->  Index Scan using stock_trans_account_trans_idx on stock_trans s  (cost=0.43..0.50 rows=1 width=4) (actual time=0.001..0.001 rows=0 loops=11455133)
               Index Cond: (account_trans_id = a.account_trans_id)
               Filter: ((product_id = 2466420) AND (credit_stock_account_id = 3))
               Rows Removed by Filter: 1
               Buffers: shared hit=43692984
 Planning time: 0.271 ms
 Execution time: 25829.316 ms
(13 rows)


Disabled indexscan:

=> set enable_indexscan=off;


                                                                      QUERY PLAN                        
------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=11049.80..11049.81 rows=1 width=4) (actual time=0.018..0.018 rows=0 loops=1)
   Buffers: shared hit=3
   ->  Sort  (cost=11049.80..11051.51 rows=682 width=4) (actual time=0.017..0.017 rows=0 loops=1)
         Sort Key: a.trans_date DESC
         Sort Method: quicksort  Memory: 25kB
         Buffers: shared hit=3
         ->  Nested Loop  (cost=35.99..11046.39 rows=682 width=4) (actual time=0.011..0.011 rows=0 loops=1)
               Buffers: shared hit=3
               ->  Bitmap Heap Scan on stock_trans s  (cost=31.59..5301.09 rows=682 width=4) (actual time=0.011..0.011 rows=0 loops=1)
                     Recheck Cond: (product_id = 2466420)
                     Filter: (credit_stock_account_id = 3)
                     Buffers: shared hit=3
                     ->  Bitmap Index Scan on stock_trans_product_idx  (cost=0.00..31.42 rows=1465 width=0) (actual time=0.009..0.009 rows=0 loops=1)
                           Index Cond: (product_id = 2466420)
                           Buffers: shared hit=3
               ->  Bitmap Heap Scan on account_trans a  (cost=4.40..8.41 rows=1 width=8) (never executed)
                     Recheck Cond: (account_trans_id = s.account_trans_id)
                     ->  Bitmap Index Scan on account_trans_pkey  (cost=0.00..4.40 rows=1 width=0) (never executed)
                           Index Cond: (account_trans_id = s.account_trans_id)
 Planning time: 0.272 ms
 Execution time: 0.047 ms
(21 rows)


Explain from the same query on the original database:


                                                                          QUERY PLAN                                                  
--------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=9811.51..9811.52 rows=1 width=4) (actual time=0.020..0.020 rows=0 loops=1)
   Buffers: shared hit=3
   ->  Sort  (cost=9811.51..9813.23 rows=685 width=4) (actual time=0.019..0.019 rows=0 loops=1)
         Sort Key: a.trans_date
         Sort Method: quicksort  Memory: 25kB
         Buffers: shared hit=3
         ->  Nested Loop  (cost=0.00..9808.09 rows=685 width=4) (actual time=0.014..0.014 rows=0 loops=1)
               Buffers: shared hit=3
               ->  Index Scan using stock_trans_product_idx on stock_trans s  (cost=0.00..3300.01 rows=685 width=4) (actual time=0.014..0.014 rows=0 loops=1)
                     Index Cond: (product_id = 2466420)
                     Filter: (credit_stock_account_id = 3)
                     Buffers: shared hit=3
               ->  Index Scan using account_trans_pkey on account_trans a  (cost=0.00..9.49 rows=1 width=8) (never executed)
                     Index Cond: (account_trans_id = s.account_trans_id)
 Total runtime: 0.050 ms
(15 rows)


Regards,
--
David 

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

Предыдущее
От: Craig James
Дата:
Сообщение: Re: Irrelevant columns cause massive performance change
Следующее
От: Tom Lane
Дата:
Сообщение: Re: Slow performance after restoring a dump