On Thu 04 Jul 2013 08:10:45 PM PET, Michael Paquier wrote:
On Fri, Jul 5, 2013 at 10:04 AM, bricklen <bricklen@xxxxxxxxx> wrote:
On Thu, Jul 4, 2013 at 5:26 PM, David Carpio <davidc@xxxxxxxxxxxxxxxxxxx>
wrote:
Also, can you supply the EXPLAIN (ANALYZE, BUFFERS) plan instead of the
simple EXPLAIN plan?
Then it might be interesting that you scan what is wrong with this utility:
http://explain.depesz.com/
--
Michael
Hello
This is the EXPLAIN ANALYZE
QUERY PLAN
Sort (cost=726512.79..726512.82 rows=11 width=196) (actual
time=884295.151..884295.178 rows=221 loops=1)
Sort Key: s0.id, o.guid, ((SubPlan 2))
Sort Method: quicksort Memory: 132kB
-> Nested Loop Anti Join (cost=595.80..726512.60 rows=11
width=196) (actual time=212913.939..884287.920 rows=221 loops=1)
Join Filter: (fl_exclude.spid = ANY (ARRAY[2407, 4, c.spid]))
-> Nested Loop Left Join (cost=595.80..726079.95 rows=17
width=208) (actual time=212912.427..884246.266 rows=221 loops=1)
-> Nested Loop Left Join (cost=595.80..726057.91 rows=17
width=167) (actual time=212912.296..884236.056 rows=221 loops=1)
Filter: ((s1a3m0.spid = ANY ('{2407,4}'::integer[])) OR (s1a3m0.spid
= c.spid) OR (s1a3m0.spid IS NULL))
Rows Removed by Filter: 7
-> Nested Loop (cost=595.80..726040.10 rows=17 width=159) (actual
time=212911.997..884213.578 rows=221 loops=1)
-> Nested Loop Left Join (cost=595.80..725977.82 rows=17
width=142) (actual time=212911.597..884187.879 rows=221 loops=1)
Join Filter: (c.id = s3.sourceid)
Rows Removed by Join Filter: 16690241
-> Nested Loop (cost=595.80..2357.82 rows=17 width=77) (actual
time=23.459..99.852 rows=171 loops=1)
Join Filter: (s0.my_table_4_id = c.id)
-> Nested Loop (cost=595.80..2336.88 rows=19 width=69) (actual
time=22.780..77.976 rows=171 loops=1)
-> Bitmap Heap Scan on my_table_3 s0 (cost=595.80..1165.50
rows=160 width=49) (actual time=22.629..48.588 rows=171 loops=1)
Recheck Cond: ((id = ANY ('{...}'::integer[])) OR (id = ANY
('{...}'::integer[])) OR (id = ANY ('{...}'::integer[])) OR
(id = ANY ('{...}'::integer[])) OR (id = ANY ('{...}'::integer[]))
OR (id = ANY ('{...}'::integer[])) OR (id = ANY ('{...}'::integer[]))
OR (id = ANY ('{...}'::integer[])))
Filter: (retired = 0::numeric)
Rows Removed by Filter: 11
-> BitmapOr (cost=595.80..595.80 rows=182 width=0) (actual
time=22.534..22.534 rows=0 loops=1)
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=5.220..5.220 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=2.278..2.278 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=3.520..3.520 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=1.791..1.791 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=3.178..3.178 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=3.657..3.657 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..81.77 rows=25
width=0) (actual time=2.245..2.245 rows=25 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Bitmap Index Scan on my_table_3_pk (cost=0.00..23.11 rows=7
width=0) (actual time=0.634..0.634 rows=7 loops=1)
Index Cond: (id = ANY ('{...}'::integer[]))
-> Index Scan using my_table_51_idx on my_table_5 s2
(cost=0.00..7.31 rows=1 width=20) (actual time=0.160..0.165 rows=1
loops=171)
Index Cond: ((my_table_2_id = s0.my_table_4_id) AND (my_table_1_id =
5435171))
-> Index Scan using my_table_4_pk on my_table_4 c (cost=0.00..1.09
rows=1 width=8) (actual time=0.096..0.117 rows=1 loops=171)
Index Cond: (id = s2.my_table_2_id)
Filter: (retired = 0::numeric)
-> Materialize (cost=0.00..723619.75 rows=1 width=69) (actual
time=4.612..5144.606 rows=97605 loops=171)
-> Nested Loop (cost=0.00..723619.75 rows=1 width=69) (actual
time=788.562..876415.024 rows=97605 loops=1)
Join Filter: (c.id = ao7.my_table_2_id)
Rows Removed by Join Filter: 1785384515
-> Nested Loop (cost=0.00..460418.49 rows=18988 width=4) (actual
time=1.638..2911.401 rows=18292 loops=1)
-> Index Scan using my_table_52_idx on my_table_5 s7
(cost=0.00..324460.90 rows=16361 width=4) (actual time=0.945..1799.632
rows=18292 loops=1)
Index Cond: (my_table_1_id = 10832605)
Filter: ((NOT (SubPlan 8)) OR (SubPlan 9))
Rows Removed by Filter: 3921
SubPlan 8
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.044..0.044 ro
ws=1 loops=22213)
Index Cond: (my_table_2_id = s7.id)
Heap Fetches: 22213
SubPlan 9
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.007..0.007 ro
ws=1 loops=22213)
Index Cond: ((my_table_2_id = s7.id) AND (startdate <=
1294617600000::bigint) AND (enddate >= 1294617600000::bigint))
Heap Fetches: 18292
-> Index Scan using my_table_9_idx on my_table_9 ao7
(cost=0.00..8.27 rows=4 width=8) (actual time=0.040..0.055 rows=1
loops=18292)
Index Cond: (my_table_9_id = s7.id)
-> Materialize (cost=0.00..262631.62 rows=2 width=89) (actual
time=0.002..20.243 rows=97610 loops=18292)
-> Nested Loop (cost=0.00..262631.61 rows=2 width=89) (actual
time=7.016..33482.141 rows=97610 loops=1)
-> Nested Loop (cost=0.00..262616.66 rows=1 width=85) (actual
time=6.734..31695.248 rows=97610 loops=1)
-> Nested Loop (cost=0.00..262602.64 rows=4 width=85) (actual
time=6.728..22212.748 rows=1272302 loops=1)
-> Nested Loop (cost=0.00..260617.71 rows=46 width=36) (actual
time=6.450..5653.369 rows=98279 loops=1)
-> Nested Loop (cost=0.00..199380.20 rows=3996 width=32) (actual
time=1.680..1560.622 rows=272880 loops=1)
-> Nested Loop (cost=0.00..150606.82 rows=16820 width=24) (actual
time=1.530..333.465 rows=17561 loops=1)
-> Index Scan using my_table_52_idx on my_table_5 s6
(cost=0.00..16383.86 rows=16820 width=20) (actual time=0.084..42.426
rows=17561 loops=1)
Index Cond: (my_table_1_id = ...)
-> Index Only Scan using my_table_2_pk on my_table_2 o
(cost=0.00..7.97 rows=1 width=4) (actual time=0.013..0.014 rows=1
loops=17561)
Index Cond: (id = s6.my_table_2_id)
Heap Fetches: 17561
-> Index Scan using my_table_7_idx on my_table_7 s3_a
(cost=0.00..2.81 rows=9 width=8) (actual time=0.017..0.059 rows=16
loops=17561)
Index Cond: (my_table_7_id = o.id)
-> Index Scan using my_table_6_pk on my_table_6 s3
(cost=0.00..15.31 rows=1 width=8) (actual time=0.013..0.013 rows=0
loops=272880)
Index Cond: (id = s3_a.my_table_6_id)
Filter: ((relationdefinitionid = ANY ('{...}'::integer[])) AND ((NOT
(SubPlan 10)) OR (SubPlan 11)))
Rows Removed by Filter: 1
SubPlan 10
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.005..0.005 rows=0
loops=98279)
Index Cond: (my_table_2_id = s3.id)
Heap Fetches: 0
SubPlan 11
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (never executed)
Index Cond: ((my_table_2_id = s3.id) AND (startdate <=
1294617600000::bigint) AND (enddate >= 1294617600000::bigint))
Heap Fetches: 0
-> Index Scan using my_table_3_idx on my_table_3 s5
(cost=0.00..43.13 rows=2 width=49) (actual time=0.019..0.158 rows=13
loops=98279)
Index Cond: (my_table_4_id = o.id)
Filter: ((retired = 0::numeric) AND ((NOT (SubPlan 6)) OR (SubPlan
7)))
Rows Removed by Filter: 2
SubPlan 6
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.005..0.005 rows=0
loops=1476591)
Index Cond: (my_table_2_id = s5.id)
Heap Fetches: 502460
SubPlan 7
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.005..0.005 rows=1
loops=502460)
Index Cond: ((my_table_2_id = s5.id) AND (startdate <=
1294617600000::bigint) AND (enddate >= 1294617600000::bigint))
Heap Fetches: 298171
-> Index Scan using my_table_2_pk on my_table_2 f5objects
(cost=0.00..3.50 rows=1 width=4) (actual time=0.006..0.007 rows=0
loops=1272302)
Index Cond: (id = s5.id)
Filter: (contentsetid = ...)
Rows Removed by Filter: 1
-> Index Scan using my_table_4_pk on my_table_4 c
(cost=0.00..14.94 rows=1 width=4) (actual time=0.015..0.016 rows=1
loops=97610)
Index Cond: (id = o.id)
Filter: ((retired = 0::numeric) AND ((NOT (SubPlan 4)) OR (SubPlan
5)))
SubPlan 4
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.006..0.006 rows=0
loops=97610)
Index Cond: (my_table_2_id = c.id)
Heap Fetches: 9369
SubPlan 5
-> Index Only Scan using my_table_81_idx on my_table_8 ovd
(cost=0.00..6.96 rows=1 width=0) (actual time=0.006..0.006 rows=1
loops=9369)
Index Cond: ((my_table_2_id = c.id) AND (startdate <=
1294617600000::bigint) AND (enddate >= 1294617600000::bigint))
Heap Fetches: 9369
-> Index Scan using my_table_2_pk on my_table_2 o (cost=0.00..3.65
rows=1 width=29) (actual time=0.098..0.098 rows=1 loops=221)
Index Cond: (id = c.id)
-> Index Scan using my_table_10_pk on my_table_10 s1a3m0
(cost=0.00..1.03 rows=1 width=12) (actual time=0.089..0.092 rows=1
loops=221)
Index Cond: (c.id = my_table_4_id)
-> Index Scan using my_table_3_pk on my_table_3 s1a3m1
(cost=0.00..1.29 rows=1 width=45) (actual time=0.042..0.042 rows=1
loops=221)
Index Cond: (s1a3m0.my_table_3_id = id)
-> Index Only Scan using my_table_10_pk on my_table_10 fl_exclude
(cost=0.00..1.04 rows=1 width=8) (actual time=0.012..0.012 rows=0
loops=221)
Index Cond: (my_table_4_id = s1a3m0.my_table_4_id)
Filter: (CASE spid WHEN 2407 THEN 2 WHEN 4 THEN 1 ELSE 0 END > CASE
s1a3m0.spid WHEN 2407 THEN 2 WHEN 4 THEN 1 ELSE 0 END)
Rows Removed by Filter: 1
Heap Fetches: 228
SubPlan 1
-> Nested Loop (cost=0.00..14.66 rows=1 width=23) (actual
time=0.040..0.041 rows=1 loops=221)
-> Index Scan using my_table_1_pk on my_table_1 fd
(cost=0.00..6.27 rows=1 width=4) (actual time=0.015..0.015 rows=1
loops=221)
Index Cond: (id = s2.my_table_1_id)
-> Index Scan using my_table_2_pk on my_table_2 o (cost=0.00..8.38
rows=1 width=27) (actual time=0.013..0.014 rows=1 loops=221)
Index Cond: (id = fd.typeid)
SubPlan 2
-> Index Scan using my_table_2_pk on my_table_2 (cost=0.00..8.38
rows=1 width=23) (actual time=0.062..0.063 rows=1 loops=221)
Index Cond: (id = s3.id)
SubPlan 3
-> Nested Loop (cost=0.00..14.66 rows=1 width=23) (actual
time=0.028..0.033 rows=1 loops=221)
-> Index Scan using my_table_1_pk on my_table_1 fd
(cost=0.00..6.27 rows=1 width=4) (actual time=0.003..0.008 rows=1
loops=221)
Index Cond: (id = s6.my_table_1_id)
-> Index Scan using my_table_2_pk on my_table_2 o (cost=0.00..8.38
rows=1 width=27) (actual time=0.009..0.009 rows=1 loops=214)
Index Cond: (id = fd.typeid)
Total runtime: 884385.637 ms
Thank you for your time
David Carpio
--
Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general
