Nested loop and simple join query - slow after upgrade to 9.2

From: alexandre - aldeia digital <adaldeia(at)gmail(dot)com>
To: pgsql-performance(at)postgresql(dot)org
Subject: Nested loop and simple join query - slow after upgrade to 9.2
Date: 2013-01-25 15:34:15
Message-ID: 5102A5F7.2070103@gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hi,

Last weekend, we upgrade a PG from 8.4 to 9.2 version (full
pg_dump/restore/vacuum/analyze). After this, some simple join querys
became very slow, maybe because the use of nested loops. Bellow, an
example with nestedloop on and off:

base=# analyze verbose pc13t;
INFO: analyzing "public.pc13t"
INFO: "pc13t": scanned 30000 of 212313 pages, containing 268677 live
rows and 764 dead rows; 30000 rows in sample, 1903065 estimated total rows
ANALYZE
base=# analyze verbose pc13t3;
INFO: analyzing "public.pc13t3"
INFO: "pc13t3": scanned 30000 of 883424 pages, containing 1274216 live
rows and 3005 dead rows; 30000 rows in sample, 37553206 estimated total rows
ANALYZE
base=# set enable_nestloop = on;
SET
base=# explain (analyze,buffers) SELECT T1.Pc13Item, T1.PC13CodPed,
T1.PC13AnoPed, T1.PC13Emp08P, T1.PC13Cor, T1.PC13Codigo, T1.PC13Emp08,
T1.PC13ProEst AS PC13ProEst, T2.PC13Grade, T4.PC07GerPed, T2.PC13EmpGra,
T1.PC13Emp06P AS PC13Emp06P, T4.PC07NaoTV, T3.co13PorTam, T4.PC07CodAlm,
T4.PC07C_Cust AS PC13SecIns, T3.co13Bloq AS PC13ProBlq, T1.PC13InsEst AS
PC13InsEst, T1.PC13TipIn2 AS PC13TipIn2, T1.PC13EmpIns AS PC13EmpIns
FROM (((PC13T3 T1 LEFT JOIN PC13T T2 ON T2.PC13Emp08 = T1.PC13Emp08 AND
T2.PC13Codigo = T1.PC13Codigo AND T2.PC13Cor = T1.PC13Cor AND
T2.PC13Emp08P = T1.PC13Emp08P AND T2.PC13AnoPed = T1.PC13AnoPed AND
T2.PC13CodPed = T1.PC13CodPed AND T2.Pc13Item = T1.Pc13Item) LEFT JOIN
CO13T T3 ON T3.co13Emp06 = T1.PC13Emp06P AND T3.co13CodPro =
T1.PC13ProEst) LEFT JOIN PC07T T4 ON T4.PC07CodEmp = T1.PC13EmpIns AND
T4.PC07Tipo = T1.PC13TipIn2 AND T4.PC07Codigo = T1.PC13InsEst) WHERE
T1.PC13Emp08 = '1' and T1.PC13Codigo = E'9487-491C ' and
T1.PC13Cor = '1' and T1.PC13Emp08P = '0' and T1.PC13AnoPed = '0' and
T1.PC13CodPed = '0' and T1.Pc13Item = '0' ORDER BY T1.PC13Emp08,
T1.PC13Codigo, T1.PC13Cor, T1.PC13Emp08P, T1.PC13AnoPed, T1.PC13CodPed,
T1.Pc13Item, T1.PC13EmpIns, T1.PC13TipIn2, T1.PC13InsEst ;

QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-----------------------------
Nested Loop Left Join (cost=0.00..20.61 rows=1 width=86) (actual
time=0.870..1197.057 rows=39 loops=1)
Buffers: shared hit=424602 read=5
-> Nested Loop Left Join (cost=0.00..16.33 rows=1 width=74)
(actual time=0.822..1196.583 rows=39 loops=1)
Buffers: shared hit=424484 read=5
-> Nested Loop Left Join (cost=0.00..12.01 rows=1 width=70)
(actual time=0.779..1195.477 rows=39 loops=1)
Join Filter: ((t2.pc13emp08 = t1.pc13emp08) AND
(t2.pc13codigo = t1.pc13codigo) AND (t2.pc13cor = t1.pc13cor) AND
(t2.pc13emp08p = t1.pc13emp08p) AND (t2.pc13anoped = t1.pc13anoped) AND
(t2.pc13codped = t1.pc13codped) AND
(t2.pc13item = t1.pc13item))
Buffers: shared hit=424329 read=5
-> Index Scan using ad_pc13t3_modpadrao on pc13t3 t1
(cost=0.00..6.21 rows=1 width=65) (actual time=0.090..0.252 rows=39 loops=1)
Index Cond: ((pc13emp08p = 0) AND (pc13anoped = 0)
AND (pc13codped = 0) AND (pc13codigo = '9487-491C '::bpchar)
AND (pc13cor = 1) AND (pc13emp08 = 1))
Buffers: shared hit=5 read=5
-> Index Scan using xpc13tc on pc13t t2
(cost=0.00..5.77 rows=1 width=44) (actual time=0.254..30.638 rows=1
loops=39)
Index Cond: ((pc13emp08p = 0) AND (pc13anoped = 0)
AND (pc13codped = 0) AND (pc13item = 0))
Filter: ((pc13emp08 = 1) AND (pc13codigo =
'9487-491C '::bpchar) AND (pc13cor = 1))
Rows Removed by Filter: 45161
Buffers: shared hit=424324
-> Index Scan using co13t_pkey on co13t t3 (cost=0.00..4.31
rows=1 width=10) (actual time=0.021..0.024 rows=1 loops=39)
Index Cond: ((co13emp06 = t1.pc13emp06p) AND (co13codpro
= t1.pc13proest))
Buffers: shared hit=155
-> Index Scan using pc07t_pkey on pc07t t4 (cost=0.00..4.28 rows=1
width=24) (actual time=0.008..0.009 rows=1 loops=39)
Index Cond: ((pc07codemp = t1.pc13empins) AND (pc07tipo =
t1.pc13tipin2) AND (pc07codigo = t1.pc13insest))
Buffers: shared hit=118
Total runtime: 1197.332 ms
(22 rows)

#######################################################

base=# set enable_nestloop = off;
SET
base=# explain (analyze,buffers) SELECT T1.Pc13Item, T1.PC13CodPed,
T1.PC13AnoPed, T1.PC13Emp08P, T1.PC13Cor, T1.PC13Codigo, T1.PC13Emp08,
T1.PC13ProEst AS PC13ProEst, T2.PC13Grade, T4.PC07GerPed, T2.PC13EmpGra,
T1.PC13Emp06P AS PC13Emp06P, T4.PC07NaoTV, T3.co13PorTam, T4.PC07CodAlm,
T4.PC07C_Cust AS PC13SecIns, T3.co13Bloq AS PC13ProBlq, T1.PC13InsEst AS
PC13InsEst, T1.PC13TipIn2 AS PC13TipIn2, T1.PC13EmpIns AS PC13EmpIns
FROM (((PC13T3 T1 LEFT JOIN PC13T T2 ON T2.PC13Emp08 = T1.PC13Emp08 AND
T2.PC13Codigo = T1.PC13Codigo AND T2.PC13Cor = T1.PC13Cor AND
T2.PC13Emp08P = T1.PC13Emp08P AND T2.PC13AnoPed = T1.PC13AnoPed AND
T2.PC13CodPed = T1.PC13CodPed AND T2.Pc13Item = T1.Pc13Item) LEFT JOIN
CO13T T3 ON T3.co13Emp06 = T1.PC13Emp06P AND T3.co13CodPro =
T1.PC13ProEst) LEFT JOIN PC07T T4 ON T4.PC07CodEmp = T1.PC13EmpIns AND
T4.PC07Tipo = T1.PC13TipIn2 AND T4.PC07Codigo = T1.PC13InsEst) WHERE
T1.PC13Emp08 = '1' and T1.PC13Codigo = E'9487-491C ' and
T1.PC13Cor = '1' and T1.PC13Emp08P = '0' and T1.PC13AnoPed = '0' and
T1.PC13CodPed = '0' and T1.Pc13Item = '0' ORDER BY T1.PC13Emp08,
T1.PC13Codigo, T1.PC13Cor, T1.PC13Emp08P, T1.PC13AnoPed, T1.PC13CodPed,
T1.Pc13Item, T1.PC13EmpIns, T1.PC13TipIn2, T1.PC13InsEst ;

QUERY PLAN

---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------
Sort (cost=7782.21..7782.21 rows=1 width=86) (actual
time=108.672..108.677 rows=39 loops=1)
Sort Key: t1.pc13empins, t1.pc13tipin2, t1.pc13insest
Sort Method: quicksort Memory: 30kB
Buffers: shared hit=15960 read=2050
-> Hash Left Join (cost=154.42..7782.20 rows=1 width=86) (actual
time=49.398..108.413 rows=39 loops=1)
Hash Cond: ((t1.pc13emp08 = t2.pc13emp08) AND (t1.pc13codigo =
t2.pc13codigo) AND (t1.pc13cor = t2.pc13cor) AND (t1.pc13emp08p =
t2.pc13emp08p) AND (t1.pc13anoped = t2.pc13anoped) AND (t1.pc13codped =
t2.pc13codped) AND (t1.pc13
item = t2.pc13item))
Buffers: shared hit=15960 read=2050
-> Hash Right Join (cost=148.62..7776.37 rows=1 width=81)
(actual time=6.392..65.317 rows=39 loops=1)
Hash Cond: ((t3.co13emp06 = t1.pc13emp06p) AND
(t3.co13codpro = t1.pc13proest))
Buffers: shared hit=5073 read=2050
-> Seq Scan on co13t t3 (cost=0.00..7371.56 rows=34156
width=10) (actual time=0.009..41.550 rows=34156 loops=1)
Buffers: shared hit=5043 read=1987
-> Hash (cost=148.61..148.61 rows=1 width=77) (actual
time=2.514..2.514 rows=39 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 5kB
Buffers: shared hit=27 read=63
-> Hash Right Join (cost=6.23..148.61 rows=1
width=77) (actual time=0.141..2.484 rows=39 loops=1)
Hash Cond: ((t4.pc07codemp = t1.pc13empins)
AND (t4.pc07tipo = t1.pc13tipin2) AND (t4.pc07codigo = t1.pc13insest))
Buffers: shared hit=27 read=63
-> Seq Scan on pc07t t4 (cost=0.00..109.88
rows=2888 width=24) (actual time=0.002..1.171 rows=2888 loops=1)
Buffers: shared hit=18 read=63
-> Hash (cost=6.21..6.21 rows=1 width=65)
(actual time=0.123..0.123 rows=39 loops=1)
Buckets: 1024 Batches: 1 Memory
Usage: 4kB
Buffers: shared hit=9
-> Index Scan using
ad_pc13t3_modpadrao on pc13t3 t1 (cost=0.00..6.21 rows=1 width=65)
(actual time=0.041..0.090 rows=39 loops=1)
Index Cond: ((pc13emp08p = 0)
AND (pc13anoped = 0) AND (pc13codped = 0) AND (pc13codigo = '9487-491C
'::bpchar) AND (pc13cor = 1) AND (pc13emp08 = 1))
Buffers: shared hit=9
-> Hash (cost=5.77..5.77 rows=1 width=44) (actual
time=42.937..42.937 rows=1 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 1kB
Buffers: shared hit=10880
-> Index Scan using xpc13tc on pc13t t2
(cost=0.00..5.77 rows=1 width=44) (actual time=0.357..42.933 rows=1 loops=1)
Index Cond: ((pc13emp08p = 0) AND (pc13anoped = 0)
AND (pc13codped = 0) AND (pc13item = 0))
Filter: ((pc13emp08 = 1) AND (pc13codigo =
'9487-491C '::bpchar) AND (pc13cor = 1))
Rows Removed by Filter: 45161
Buffers: shared hit=10880
Total runtime: 108.884 ms
(35 rows)

Nested loop is ~12 times slower in this case. The server parameters are
the same. Unfortunattly, I don't have the explain in 8.4 version.
And I noticed that the server load grew after the upgrade.

Best regards,

Alexandre

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Jeff Janes 2013-01-25 18:29:28 Re: Nested loop and simple join query - slow after upgrade to 9.2
Previous Message Sachin D. Kotwal 2013-01-25 06:38:32 DML's to tpcw benchmark for postgresql