The following bug has been logged on the website:
Bug reference: 14871
Logged by: Andy Kinney
Email address: banzaitron@comcast.net
PostgreSQL version: 10.0
Operating system: CentOS7
Description:
Hello,
I apologize if this is submitted to the wrong place, let me know if I need
to send it elsewhere (I am having a hard time finding info on this). We
chose Postgresql for a fairly large project because of its recent support
for RLS. I understand there were some performance problems early on in 9.6
related to joins of large tables. My understanding is that those were
resolved in 10.0. I am experiencing some very strange query plans with and
without RLS enabled. The optimizer is performing sequential scans of a huge
table when enabled. Here is a plan showing the difference with and without
(Elset is a large table, Onorbit is smaller (about 20000 rows), and
Currentelset is a table that maps a single 'current' Elset row for each
Onorbit row). Each PK/FK have appropriate indices defined and queries
against the large table alone are very fast so I believe the POLICY I've put
on the table is not the issue:
explain (buffers, analyze) select elset0_.* from "Currentelset" currentels3_ inner join
"Elset"elset0_ on currentels3_."idElset"=elset0_."idElset" inner join "Onorbit" onorbit1_
on elset0_."OnOrbit_idOnOrbit"=onorbit1_."idOnOrbit"
QUERY
PLAN
----------------------------------------------------------------------------------------------------
----------------------------------------------Nested Loop (cost=689.08..49670.49 rows=1058 width=378) (actual
time=2832.039..102802.046 rows=169
24 loops=1) Buffers: shared hit=7136232 read=2618 -> Hash Join (cost=688.79..48017.34 rows=4231 width=378) (actual
time=2831.915..100814.347 rows
=16924 loops=1) Hash Cond: ((elset0_."idElset")::text =
(currentels3_."idElset")::text) Buffers: shared hit=6966945 read=2618 -> Seq Scan on "Elset" elset0_
(cost=0.00..46037.32rows=102276
width=378) (actual time=0
.392..100401.072 rows=409104 loops=1) Filter: ((SubPlan 1) AND (SubPlan 2)) Buffers: shared
hit=6966637read=2618 SubPlan 1 -> Result (cost=0.00..0.04 rows=1 width=1) (actual
time=0.185..0.185 rows=1 loops
=409104) Buffers: shared hit=5319530 SubPlan 2 -> Result
(cost=0.00..0.04rows=1 width=1) (actual
time=0.057..0.057 rows=1 loops
=409104) Buffers: shared hit=1636416 -> Hash (cost=477.24..477.24 rows=16924 width=37)
(actual
time=7.707..7.707 rows=16924 lo
ops=1) Buckets: 32768 Batches: 1 Memory Usage: 1397kB Buffers: shared hit=308
-> Seq Scan on "Currentelset" currentels3_
(cost=0.00..477.24 rows=16924 width=37)
(actual time=0.008..3.519 rows=16924 loops=1) Buffers: shared hit=308 -> Index Scan using
onorbit_pkeyon "Onorbit" onorbit1_
(cost=0.29..0.39 rows=1 width=5) (actua
l time=0.115..0.115 rows=1 loops=16924) Index Cond: (("idOnOrbit")::text =
(elset0_."OnOrbit_idOnOrbit")::text) Filter: ((SubPlan 3) AND (SubPlan 4)) Buffers: shared hit=169287
SubPlan 3 -> Result (cost=0.00..0.04 rows=1 width=1) (actual
time=0.050..0.050 rows=1 loops=16924
) Buffers: shared hit=50772 SubPlan 4 -> Result (cost=0.00..0.04 rows=1 width=1)
(actual
time=0.053..0.053 rows=1 loops=16924
) Buffers: shared hit=67696Planning time: 0.934 msExecution time: 102805.236 ms
(31 rows)
Without RLS:
explain (buffers, analyze) select elset0_.* from "Currentelset" currentels3_ inner join
"Elset"elset0_ on currentels3_."idElset"=elset0_."idElset" inner join "Onorbit" onorbit1_
on elset0_."OnOrbit_idOnOrbit"=onorbit1_."idOnOrbit"
QUERY
PLAN
----------------------------------------------------------------------------------------------------
----------------------------------------------------Gather (cost=2461.39..21408.48 rows=16924 width=378) (actual
time=27.768..123.132 rows=16924 loops
=1) Workers Planned: 2 Workers Launched: 2 Buffers: shared hit=13167 read=2588 -> Hash Join
(cost=1461.39..18716.08rows=7052 width=378) (actual
time=39.811..106.877 rows=564
1 loops=3) Hash Cond: ((elset0_."OnOrbit_idOnOrbit")::text =
(onorbit1_."idOnOrbit")::text) Buffers: shared hit=12817 read=2586 -> Hash Join (cost=688.79..17854.45
rows=7052width=378) (actual
time=24.560..87.577 rows
=5641 loops=3) Hash Cond: ((elset0_."idElset")::text =
(currentels3_."idElset")::text) Buffers: shared hit=11647 read=2586 -> Parallel Seq Scan on
"Elset"elset0_
(cost=0.00..15013.60 rows=170460 width=378)(actual time=0.040..38.353 rows=136368 loops=3) Buffers:
sharedhit=10723 read=2586 -> Hash (cost=477.24..477.24 rows=16924 width=37) (actual
time=9.986..9.986 rows=16
924 loops=3) Buckets: 32768 Batches: 1 Memory Usage: 1397kB Buffers: shared
hit=924 -> Seq Scan on "Currentelset" currentels3_
(cost=0.00..477.24 rows=16924 widt
h=37) (actual time=0.026..4.435 rows=16924 loops=3) Buffers: shared hit=924 -> Hash
(cost=536.71..536.71rows=18871 width=5) (actual
time=14.747..14.747 rows=18871 l
oops=3) Buckets: 32768 Batches: 1 Memory Usage: 954kB Buffers: shared hit=1044
-> Seq Scan on "Onorbit" onorbit1_ (cost=0.00..536.71
rows=18871 width=5) (actual t
ime=0.033..7.587 rows=18871 loops=3) Buffers: shared hit=1044Planning time: 1.478 msExecution time:
127.713ms
(24 rows)
--
Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs