BUG #15233: Error in estimation leads to very bad parralel plan in simple 2 table join.

Started by PG Bug reporting formalmost 8 years ago3 messagesbugs
Jump to latest
#1PG Bug reporting form
noreply@postgresql.org

The following bug has been logged on the website:

Bug reference: 15233
Logged by: Maxim Boguk
Email address: mb@dataegret.com
PostgreSQL version: 9.6.8
Operating system: Linux Ubuntu
Description:

Original query:

SELECT * FROM resume r
INNER JOIN area a ON (r.area_id = a.area_id)
where
(a.path LIKE '%.1806.%')
AND r.is_finished IN(1, 2, 9)
AND r.disabled = false
AND r.access_type IN (1, 2, 3, 5)
AND r.desireable_compensation_currency_code = 'RUR' AND
r.desireable_compensation >= 1 AND r.desireable_compensation <= 30000
AND r.post NOT ILIKE '%Руководитель%' AND r.post NOT ILIKE
'%Директор%' AND r.post NOT ILIKE '%Начальник%' AND r.post NOT ILIKE
'%Заместитель руководителя%' AND r.post NOT ILIKE '%Заместитель начальника%'
AND r.post NOT ILIKE '%Вице-президент%' AND r.post NOT ILIKE '%Заместитель
директора%' AND r.post NOT ILIKE '%Управляющий%' AND r.post NOT ILIKE
'%Заместитель управляющего%'
AND 2 = ANY (employments);

Bad plan (normal settings):

Nested Loop (cost=100.00..1281887.84 rows=35 width=614) (actual
time=361757.698..2084527.877 rows=4496 loops=1)
Join Filter: (r.area_id = a.area_id)
Rows Removed by Join Filter: 9186603
-> Seq Scan on area a (cost=0.00..265.70 rows=1 width=106) (actual
time=0.669..1.756 rows=23 loops=1)
Filter: ((path)::text ~~ '%.1806.%'::text)
Rows Removed by Filter: 5076
-> Gather (cost=100.00..1272588.91 rows=178876 width=508) (actual
time=0.205..90588.432 rows=399613 loops=23)
Workers Planned: 8
Workers Launched: 8
-> Parallel Seq Scan on resume r (cost=0.00..1270700.15
rows=22360 width=508) (actual time=0.692..41168.395 rows=57806 loops=159)
Filter: ((NOT disabled) AND (desireable_compensation >= 1)
AND (desireable_compensation <= 30000) AND (post !~~*
'%Руководитель%'::text) AND (post !~~* '%Директор%'::text) AND (post !~~*
'%Начальник%'::text) AND (post !~~* '%Заместитель руководителя%'::text) AND
(post !~~* '%Заместитель начальника%'::text) AND (post !~~*
'%Вице-президент%'::text) AND (post !~~* '%Заместитель директора%'::text)
AND (post !~~* '%Управляющий%'::text) AND (post !~~* '%Заместитель
управляющего%'::text) AND (desireable_compensation_currency_code =
'RUR'::bpchar) AND (is_finished = ANY ('{1,2,9}'::integer[])) AND
(access_type = ANY ('{1,2,3,5}'::integer[])) AND (2 = ANY (employments)))
Rows Removed by Filter: 12575133
Planning time: 2.953 ms
Execution time: 2084537.882 ms

Problem with estimation of selectivity
-> Seq Scan on area a (cost=0.00..265.70 rows=1 width=106) (actual
time=0.669..1.756 rows=23 loops=1)
Filter: ((path)::text ~~ '%.1806.%'::text)
leads to very dangerous idea to perform nested loop with very heavy parallel
plan inside.

Normal plan with set enable_nestloop = 0;
perform almost 100 times better:

Gather (cost=365.75..1271083.22 rows=35 width=614) (actual
time=192.640..31459.920 rows=4496 loops=1)
Workers Planned: 8
Workers Launched: 8
-> Hash Join (cost=265.75..1270982.87 rows=4 width=614) (actual
time=107.194..31447.124 rows=500 loops=9)
Hash Cond: (r.area_id = a.area_id)
-> Parallel Seq Scan on resume r (cost=0.00..1270700.15
rows=22360 width=508) (actual time=0.854..31438.614 rows=44401 loops=9)
Filter: ((NOT disabled) AND (desireable_compensation >= 1)
AND (desireable_compensation <= 30000) AND (post !~~*
'%Руководитель%'::text) AND (post !~~* '%Директор%'::text) AND (post !~~*
'%Начальник%'::text) AND (post !~~* '%Заместитель руководителя%'::text) AND
(post !~~* '%Заместитель начальника%'::text) AND (post !~~*
'%Вице-президент%'::text) AND (post !~~* '%Заместитель директора%'::text)
AND (post !~~* '%Управляющий%'::text) AND (post !~~* '%Заместитель
управляющего%'::text) AND (desireable_compensation_currency_code =
'RUR'::bpchar) AND (is_finished = ANY ('{1,2,9}'::integer[])) AND
(access_type = ANY ('{1,2,3,5}'::integer[])) AND (2 = ANY (employments)))
Rows Removed by Filter: 9659153
-> Hash (cost=265.70..265.70 rows=1 width=106) (actual
time=1.260..1.260 rows=23 loops=9)
Buckets: 1024 Batches: 1 Memory Usage: 11kB
-> Seq Scan on area a (cost=0.00..265.70 rows=1 width=106)
(actual time=0.546..1.250 rows=23 loops=9)
Filter: ((path)::text ~~ '%.1806.%'::text)
Rows Removed by Filter: 5076
Planning time: 2.914 ms
Execution time: 31469.176 ms

May be there should be some penalization plans of first kind (with nested
loop over heavy parallel plan) to take into account chance of estimation
error in leading part of nested loop in cases when estimated only 1 row.

PS: I not even knew before that the PostgreSQL can perform parallel seq scan
inside nested loop. Never seen such plans before.

#2Amit Kapila
amit.kapila16@gmail.com
In reply to: PG Bug reporting form (#1)
Re: BUG #15233: Error in estimation leads to very bad parralel plan in simple 2 table join.

On Fri, Jun 8, 2018 at 3:05 AM, PG Bug reporting form
<noreply@postgresql.org> wrote:

The following bug has been logged on the website:

Bug reference: 15233
Logged by: Maxim Boguk
Email address: mb@dataegret.com
PostgreSQL version: 9.6.8
Operating system: Linux Ubuntu
Description:

Original query:

SELECT * FROM resume r
INNER JOIN area a ON (r.area_id = a.area_id)
where
(a.path LIKE '%.1806.%')
AND r.is_finished IN(1, 2, 9)
AND r.disabled = false
AND r.access_type IN (1, 2, 3, 5)
AND r.desireable_compensation_currency_code = 'RUR' AND
r.desireable_compensation >= 1 AND r.desireable_compensation <= 30000
AND r.post NOT ILIKE '%Руководитель%' AND r.post NOT ILIKE
'%Директор%' AND r.post NOT ILIKE '%Начальник%' AND r.post NOT ILIKE
'%Заместитель руководителя%' AND r.post NOT ILIKE '%Заместитель начальника%'
AND r.post NOT ILIKE '%Вице-президент%' AND r.post NOT ILIKE '%Заместитель
директора%' AND r.post NOT ILIKE '%Управляющий%' AND r.post NOT ILIKE
'%Заместитель управляющего%'
AND 2 = ANY (employments);

Bad plan (normal settings):

Nested Loop (cost=100.00..1281887.84 rows=35 width=614) (actual
time=361757.698..2084527.877 rows=4496 loops=1)
Join Filter: (r.area_id = a.area_id)
Rows Removed by Join Filter: 9186603
-> Seq Scan on area a (cost=0.00..265.70 rows=1 width=106) (actual
time=0.669..1.756 rows=23 loops=1)
Filter: ((path)::text ~~ '%.1806.%'::text)
Rows Removed by Filter: 5076
-> Gather (cost=100.00..1272588.91 rows=178876 width=508) (actual
time=0.205..90588.432 rows=399613 loops=23)
Workers Planned: 8
Workers Launched: 8
-> Parallel Seq Scan on resume r (cost=0.00..1270700.15
rows=22360 width=508) (actual time=0.692..41168.395 rows=57806 loops=159)
Filter: ((NOT disabled) AND (desireable_compensation >= 1)
AND (desireable_compensation <= 30000) AND (post !~~*
'%Руководитель%'::text) AND (post !~~* '%Директор%'::text) AND (post !~~*
'%Начальник%'::text) AND (post !~~* '%Заместитель руководителя%'::text) AND
(post !~~* '%Заместитель начальника%'::text) AND (post !~~*
'%Вице-президент%'::text) AND (post !~~* '%Заместитель директора%'::text)
AND (post !~~* '%Управляющий%'::text) AND (post !~~* '%Заместитель
управляющего%'::text) AND (desireable_compensation_currency_code =
'RUR'::bpchar) AND (is_finished = ANY ('{1,2,9}'::integer[])) AND
(access_type = ANY ('{1,2,3,5}'::integer[])) AND (2 = ANY (employments)))
Rows Removed by Filter: 12575133
Planning time: 2.953 ms
Execution time: 2084537.882 ms

Problem with estimation of selectivity
-> Seq Scan on area a (cost=0.00..265.70 rows=1 width=106) (actual
time=0.669..1.756 rows=23 loops=1)
Filter: ((path)::text ~~ '%.1806.%'::text)
leads to very dangerous idea to perform nested loop with very heavy parallel
plan inside.

Is it because you have not performed Analyze on the 'area' or is it
something else due to which there is such a deviation in estimation?

--
With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com

#3Maxim Boguk
maxim.boguk@gmail.com
In reply to: Amit Kapila (#2)
Re: BUG #15233: Error in estimation leads to very bad parralel plan in simple 2 table join.

Planning time: 2.953 ms
Execution time: 2084537.882 ms

Problem with estimation of selectivity
-> Seq Scan on area a (cost=0.00..265.70 rows=1 width=106) (actual
time=0.669..1.756 rows=23 loops=1)

​​
Filter: ((path)::text ~~ '%.1806.%'::text)

leads to very dangerous idea to perform nested loop with very heavy

parallel

plan inside.

Is it because you have not performed Analyze on the 'area' or is it
something else due to which there is such a deviation in estimation?

​Hi,​

I don't think there is good way estimate selectivity of

Filter: ((path)::text ~~ '%.1806.%'::text)

But problem that there huge difference in real plan cost with exactly 1 row
vs 2 or more rows estimated. Problem still exists without parallel plan
involved, where is leads to 23 seq scan over table with 100M rows :(.

--
Maxim Boguk
Senior Postgresql DBA
http://dataegret.com/ <http://www.postgresql-consulting.com/&gt;

Phone RU: +7 985 433 0000
Phone UA: +380 99 143 0000
Phone AU: +61 45 218 5678

LinkedIn: http://www.linkedin.com/pub/maksym-boguk/80/b99/b1b
Skype: maxim.boguk

"Доктор, вы мне советовали так не делать, но почему мне по-прежнему больно
когда я так делаю ещё раз?"