Inefficient Query Plans

Поиск
Список
Период
Сортировка
От Luke Chambers
Тема Inefficient Query Plans
Дата
Msg-id 1109110085.769681.93070@g14g2000cwa.googlegroups.com
обсуждение исходный текст
Ответы Re: Inefficient Query Plans  (Tom Lane <tgl@sss.pgh.pa.us>)
Список pgsql-performance
The following query plans both result from the very same query run on
different servers. They obviously differ drastically, but I don't why
as one db is a slonied copy of the other with identical postgresql.conf
files.
Both databases are vacuum analyzed nightly.

Here is the query:
------------------------------------------------------------------------
EXPLAIN ANALYZE
SELECT COUNT(DISTINCT(t.id)) FROM (
  SELECT m_object_paper.id
    FROM m_object_paper, m_assignment, m_class,
r_comment_rubric_user_object
    WHERE m_object_paper.assignment=m_assignment.id
    AND m_assignment.class=m_class.id
    AND m_class.account IN (SELECT * FROM children_of(32660) as acts)
    AND m_object_paper.id = r_comment_rubric_user_object.objectid
 UNION
  SELECT m_object_paper.id
    FROM m_object_paper, m_assignment, m_class, r_quickmark_user_object
    WHERE m_object_paper.assignment=m_assignment.id
    AND m_assignment.class=m_class.id
    AND m_class.account IN (SELECT * FROM children_of(32660) acts)
    AND m_object_paper.id = r_quickmark_user_object.objectid)as t;
------------------------------------------------------------------------

-------------------
DB1 QUERY PLAN


--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate  (cost=314616.49..314616.49 rows=1 width=4) (actual
time=853.483..853.484 rows=1 loops=1)
   ->  Subquery Scan t  (cost=314568.97..314609.70 rows=2715 width=4)
(actual time=848.574..852.912 rows=354 loops=1)
         ->  Unique  (cost=314568.97..314582.55 rows=2715 width=4)
(actual time=848.568..852.352 rows=354 loops=1)
               ->  Sort  (cost=314568.97..314575.76 rows=2715 width=4)
(actual time=848.565..850.264 rows=2428 loops=1)
                     Sort Key: id
                     ->  Append  (cost=153181.39..314414.12 rows=2715
width=4) (actual time=224.984..844.714 rows=2428 loops=1)
                           ->  Subquery Scan "*SELECT* 1"
(cost=153181.39..159900.66 rows=2250 width=4) (actual
time=224.981..700.687 rows=2116 loops=1)
                                 ->  Hash Join
(cost=153181.39..159878.16 rows=2250 width=4) (actual
time=224.975..696.639 rows=2116 loops=1)
                                       Hash Cond: ("outer".objectid =
"inner".id)
                                       ->  Seq Scan on
r_comment_rubric_user_object  (cost=0.00..5144.18 rows=306018 width=4)
(actual time=0.021..405.881 rows=306392 loops=1)
                                       ->  Hash
(cost=153072.40..153072.40 rows=43595 width=4) (actual
time=32.311..32.311 rows=0 loops=1)
                                             ->  Nested Loop
(cost=15.00..153072.40 rows=43595 width=4) (actual time=0.554..29.762
rows=2033 loops=1)
                                                   ->  Nested Loop
(cost=15.00..16071.65 rows=3412 width=4) (actual time=0.512..3.657
rows=180 loops=1)
                                                         ->  Nested
Loop  (cost=15.00..3769.73 rows=1666 width=4) (actual time=0.452..0.943
rows=50 loops=1)
                                                               ->
HashAggregate  (cost=15.00..15.00 rows=200 width=4) (actual
time=0.388..0.394 rows=1 loops=1)
                                                                     ->
 Function Scan on children_of acts  (cost=0.00..12.50 rows=1000
width=4) (actual time=0.376..0.377 rows=1 loops=1)
                                                               ->
Index Scan using m_class_account_idx on m_class  (cost=0.00..18.67
rows=8 width=8) (actual time=0.057..0.416 rows=50 loops=1)

Index Cond: (m_class.account = "outer".acts)
                                                         ->  Index Scan
using m_assignment_class_idx on m_assignment  (cost=0.00..7.25 rows=11
width=8) (actual time=0.023..0.043 rows=4 loops=50)
                                                               Index
Cond: (m_assignment."class" = "outer".id)
                                                   ->  Index Scan using
m_object_paper_assignment_idx on m_object_paper  (cost=0.00..39.24
rows=73 width=8) (actual time=0.026..0.118 rows=11 loops=180)
                                                         Index Cond:
(m_object_paper."assignment" = "outer".id)
                           ->  Subquery Scan "*SELECT* 2"
(cost=153181.39..154513.46 rows=465 width=4) (actual
time=54.883..140.747 rows=312 loops=1)
                                 ->  Hash Join
(cost=153181.39..154508.81 rows=465 width=4) (actual
time=54.875..140.161 rows=312 loops=1)
                                       Hash Cond: ("outer".objectid =
"inner".id)
                                       ->  Seq Scan on
r_quickmark_user_object  (cost=0.00..1006.85 rows=63185 width=4)
(actual time=0.007..70.446 rows=63268 loops=1)
                                       ->  Hash
(cost=153072.40..153072.40 rows=43595 width=4) (actual
time=17.633..17.633 rows=0 loops=1)
                                             ->  Nested Loop
(cost=15.00..153072.40 rows=43595 width=4) (actual time=0.549..15.186
rows=2033 loops=1)
                                                   ->  Nested Loop
(cost=15.00..16071.65 rows=3412 width=4) (actual time=0.515..2.406
rows=180 loops=1)
                                                         ->  Nested
Loop  (cost=15.00..3769.73 rows=1666 width=4) (actual time=0.482..0.792
rows=50 loops=1)
                                                               ->
HashAggregate  (cost=15.00..15.00 rows=200 width=4) (actual
time=0.443..0.449 rows=1 loops=1)
                                                                     ->
 Function Scan on children_of acts  (cost=0.00..12.50 rows=1000
width=4) (actual time=0.428..0.429 rows=1 loops=1)
                                                               ->
Index Scan using m_class_account_idx on m_class  (cost=0.00..18.67
rows=8 width=8) (actual time=0.029..0.219 rows=50 loops=1)

Index Cond: (m_class.account = "outer".acts)
                                                         ->  Index Scan
using m_assignment_class_idx on m_assignment  (cost=0.00..7.25 rows=11
width=8) (actual time=0.013..0.023 rows=4 loops=50)
                                                               Index
Cond: (m_assignment."class" = "outer".id)
                                                   ->  Index Scan using
m_object_paper_assignment_idx on m_object_paper  (cost=0.00..39.24
rows=73 width=8) (actual time=0.011..0.048 rows=11 loops=180)
                                                         Index Cond:
(m_object_paper."assignment" = "outer".id)
 Total runtime: 854.101 ms




-------------------
DB2 QUERY PLAN


---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate  (cost=431500.82..431500.82 rows=1 width=4) (actual
time=161604.563..161604.568 rows=1 loops=1)
  ->  Subquery Scan t  (cost=431025.16..431432.86 rows=27180 width=4)
(actual time=161571.533..161602.095 rows=354 loops=1)
         ->  Unique  (cost=431025.16..431161.06 rows=27180 width=4)
(actual time=161571.515..161598.311 rows=354 loops=1)
               ->  Sort  (cost=431025.16..431093.11 rows=27180 width=4)
(actual time=161571.502..161583.783 rows=2428 loops=1)
                     Sort Key: id
                     ->  Append  (cost=203789.85..429023.32 rows=27180
width=4) (actual time=79513.023..161555.122 rows=2428 loops=1)
                           ->  Subquery Scan "*SELECT* 1"
(cost=203789.85..216527.64 rows=22528 width=4) (actual
time=79513.012..82516.102 rows=2116 loops=1)
                                 ->  Hash Join
(cost=203789.85..216302.36 rows=22528 width=4) (actual
time=79512.998..82493.092 rows=2116 loops=1)
                                       Hash Cond: ("outer".objectid =
"inner".id)
                                       ->  Seq Scan on
r_comment_rubric_user_object  (cost=0.00..5133.34 rows=306034 width=4)
(actual time=0.045..1769.838 rows=306390 loops=1)
                                       ->  Hash
(cost=201205.35..201205.35 rows=436601 width=4) (actual
time=78627.830..78627.830 rows=0 loops=1)
                                             ->  Hash Join
(cost=25006.81..201205.35 rows=436601 width=4) (actual
time=9572.704..78612.859 rows=2033 loops=1)
                                                   Hash Cond:
("outer"."assignment" = "inner".id)
                                                   ->  Seq Scan on
m_object_paper  (cost=0.00..142176.19 rows=5931219 width=8) (actual
time=0.085..36433.616 rows=5934777 loops=1)
                                                   ->  Hash
(cost=24921.40..24921.40 rows=34160 width=4) (actual
time=8636.897..8636.897 rows=0 loops=1)
                                                         ->  Hash Join
(cost=8773.25..24921.40 rows=34160 width=4) (actual
time=3013.277..8635.612 rows=180 loops=1)
                                                               Hash
Cond: ("outer"."class" = "inner".id)
                                                               ->  Seq
Scan on m_assignment  (cost=0.00..13486.37 rows=464037 width=8) (actual
time=0.037..2903.799 rows=464639 loops=1)
                                                               ->  Hash
 (cost=8731.55..8731.55 rows=16682 width=4) (actual
time=2985.051..2985.051 rows=0 loops=1)
                                                                     ->
 Hash Join  (cost=15.50..8731.55 rows=16682 width=4) (actual
time=716.452..2984.651 rows=50 loops=1)

   Hash Cond: ("outer".account = "inner".acts)

   ->  Seq Scan on m_class  (cost=0.00..7416.15 rows=226615 width=8)
(actual time=0.042..1586.784 rows=226796 loops=1)

   ->  Hash  (cost=15.00..15.00 rows=200 width=4) (actual
time=0.548..0.548 rows=0 loops=1)

         ->  HashAggregate  (cost=15.00..15.00 rows=200 width=4)
(actual time=0.519..0.527 rows=1 loops=1)

               ->  Function Scan on children_of acts  (cost=0.00..12.50
rows=1000 width=4) (actual time=0.485..0.491 rows=1 loops=1)
                           ->  Subquery Scan "*SELECT* 2"
(cost=203789.85..212495.68 rows=4652 width=4) (actual
time=78431.905..79014.599 rows=312 loops=1)
                                 ->  Hash Join
(cost=203789.85..212449.16 rows=4652 width=4) (actual
time=78431.889..79011.085 rows=312 loops=1)
                                       Hash Cond: ("outer".objectid =
"inner".id)
                                       ->  Seq Scan on
r_quickmark_user_object  (cost=0.00..1006.95 rows=63195 width=4)
(actual time=0.085..391.887 rows=63268 loops=1)
                                       ->  Hash
(cost=201205.35..201205.35 rows=436601 width=4) (actual
time=78182.649..78182.649 rows=0 loops=1)
                                             ->  Hash Join
(cost=25006.81..201205.35 rows=436601 width=4) (actual
time=9328.018..78167.922 rows=2033 loops=1)
                                                   Hash Cond:
("outer"."assignment" = "inner".id)
                                                   ->  Seq Scan on
m_object_paper  (cost=0.00..142176.19 rows=5931219 width=8) (actual
time=0.052..36243.971 rows=5934777 loops=1)
                                                   ->  Hash
(cost=24921.40..24921.40 rows=34160 width=4) (actual
time=8416.317..8416.317 rows=0 loops=1)
                                                         ->  Hash Join
(cost=8773.25..24921.40 rows=34160 width=4) (actual
time=2801.934..8415.065 rows=180 loops=1)
                                                               Hash
Cond: ("outer"."class" = "inner".id)
                                                               ->  Seq
Scan on m_assignment  (cost=0.00..13486.37 rows=464037 width=8) (actual
time=0.121..2899.409 rows=464639 loops=1)
                                                               ->  Hash
 (cost=8731.55..8731.55 rows=16682 width=4) (actual
time=2772.260..2772.260 rows=0 loops=1)
                                                                     ->
 Hash Join  (cost=15.50..8731.55 rows=16682 width=4) (actual
time=674.259..2771.886 rows=50 loops=1)

   Hash Cond: ("outer".account = "inner".acts)

   ->  Seq Scan on m_class  (cost=0.00..7416.15 rows=226615 width=8)
(actual time=0.049..1430.376 rows=226796 loops=1)

   ->  Hash  (cost=15.00..15.00 rows=200 width=4) (actual
time=0.647..0.647 rows=0 loops=1)

         ->  HashAggregate  (cost=15.00..15.00 rows=200 width=4)
(actual time=0.604..0.613 rows=1 loops=1)

               ->  Function Scan on children_of acts  (cost=0.00..12.50
rows=1000 width=4) (actual time=0.568..0.574 rows=1 loops=1)

Total runtime: 161605.867

--------------------------
--------------------------
Additionally, we have a db3 which was originally in agreement w/ db1
and
executing the more efficient plan. However, now it is in agreement with
db2
with the less efficient, slower plan.

What could be causing this?

Thanks for your help.


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

Предыдущее
От: Butkus_Charles@emc.com
Дата:
Сообщение: Joins, Deletes and Indexes
Следующее
От: "Vig, Sandor (G/FI-2)"
Дата:
Сообщение: PostgreSQL is extremely slow on Windows