Thread: unoptimized nested loops

unoptimized nested loops

From
Tim Kelly
Date:
Hello Everyone,
I am stumped as to what I am doing wrong.  I have two tables

metadata: parent table, 1.28m records
data: child table, 1.24m records

metadata contains descriptions of the records in data.  data has two 
fields of concern, the id field, which is a foreign key to an identical 
field in metadata, and the content field, which contains text ranging 
from a few hundred to a few thousand characters.  The id fields are 
alphanumeric for historical reasons.  Table descriptions below, some 
fields omitted for brevity:


c_db=> \d metadata 
 
   Table "public.metadata"
       Column      |           Type           | Modifiers
------------------+--------------------------+-----------
  id               | character varying(60)    | not null
  author           | character varying(90)    |

Indexes:
     "metadata_pkey" PRIMARY KEY, btree (id)
Referenced by:
     TABLE "data" CONSTRAINT "fk_metadata" FOREIGN KEY (id) REFERENCES 
metadata(id)


c_db=> \d data
             Table "public.data"
  Column  |          Type           | Modifiers
---------+-------------------------+-----------
  id      | character varying(30)   | not null
  content | text                    |

Indexes:
     "data_pkey" PRIMARY KEY, btree (id)
Foreign-key constraints:
     "fk_metadata" FOREIGN KEY (id) REFERENCES metadata(id)




I am regularly needing to search the content field in data for short 
text segments.  I can reduce the number of rows needing to be searched 
by looking for particular types of entries in metadata.  However, 
postgresql is apparently refusing to do so, and insists on searching the 
entire content column in the data table for the text segment of 
interest.  It takes more time to search the effort to reduce than the 
entire data table straight up.

To be specific with two approaches:

c_db=> select count(id) from data;
   count
---------
  1248954
(1 row)

Time: 648.358 ms


ic_db=> select count(id) from data where content like '%some text%';
   count
---------
  1167810
(1 row)

Time: 180144.251 ms


c_db=>select count(id) from metadata where author like '%Kelly%';

  count
-------
   3558
(1 row)

Time: 1625.455 ms


c_db=>select count(id) from data where data.content like '%some text%' 
and data.id in (select id from metadata where metadata.author like 
'%Kelly%');

  count
-------
    152
(1 row)

Time: 211010.598 ms


c_db=> explain analyze select count(id) from data where data.content 
like '%some text%' and data.id in (select id from metadata where 
metadata.author like '%Kelly%');

                                                                 QUERY 
PLAN

-------------------------------------------------------------------------------------------------------------------------------------------
  Aggregate  (cost=48203.30..48203.31 rows=1 width=124) (actual 
time=213021.968..213021.969 rows=1 loops=1)
    ->  Nested Loop Semi Join  (cost=0.00..48202.99 rows=125 width=124) 
(actual time=51392.697..213021.848 rows=152 loops=1)
          ->  Seq Scan on data  (cost=0.00..47132.93 rows=125 width=135) 
(actual time=0.176..183040.366 rows=1167810 loops=1)
                Filter: (data ~~ '%some text%'::text)
          ->  Index Scan using metadata_pkey on metadata 
(cost=0.00..8.55 rows=1 width=11) (actual time=0.025..0.025 rows=0 
loops=1167810)
                Index Cond: ((metadata.id)::text = (data.id)::text)
                Filter: ((metadata.author)::text ~~ '%Kelly%'::text)
  Total runtime: 213022.028 ms
(8 rows)

Time: 213024.273 ms


Alternatively, using an inner join,


c_db=> select count(id) from data inner join metadata on data.id = 
metadata.id where data.content like '%some text%' and metadata.author 
like '%Kelly%';

  count
-------
    152
(1 row)

Time: 212211.047 ms

c_db=> explain analyze select count(id) from data inner join metadata on 
data.id = metadata.id where data.context like '%some text%' and 
metadata.author like '%Kelly%';
                                                                 QUERY 
PLAN

-------------------------------------------------------------------------------------------------------------------------------------------
  Aggregate  (cost=48203.30..48203.31 rows=1 width=124) (actual 
time=212800.026..212800.026 rows=1 loops=1)
    ->  Nested Loop  (cost=0.00..48202.99 rows=125 width=124) (actual 
time=22463.361..212799.911 rows=152 loops=1)
          ->  Seq Scan on data  (cost=0.00..47132.93 rows=125 width=135) 
(actual time=0.542..182952.708 rows=1167810 loops=1)
                Filter: (data ~~ '%some text%'::text)
          ->  Index Scan using metadata_pkey on metadata 
(cost=0.00..8.55 rows=1 width=11) (actual time=0.025..0.025 rows=0 
loops=1167810)
                Index Cond: ((metadata.id)::text = (data.id)::text)
                Filter: ((metadata.author)::text ~~ '%Kelly%'::text)
  Total runtime: 212800.076 ms
(8 rows)

Time: 212805.008 ms



I do not see evidence that the nested loop is trying to reduce overhead 
by using the smaller set.  It seems to want to scan on data first either 
way.

I have run vacuum analyze, in the hopes that the optimizer is 
miscalculating, to no avail.  I seem to be unable to force postgresql to 
use the smaller set to reduce the search, even with the use of "in" on a 
subquery.

Does anyone have any ideas about what I am doing wrong on such a 
fundamentally normal operation?  I am sure I am missing something really 
obvious, but I can't even find discussions about forcing the use of 
smaller sets.  I apologize for having to ask about something that is 
almost certainly trivial.

I am not subscribed to the list; please reply-all or offline.

Thank you,
tim



Re: unoptimized nested loops

From
David Rowley
Date:
On Wed, 1 Jun 2022 at 08:04, Tim Kelly <gtkelly@dialectronics.com> wrote:
>           ->  Seq Scan on data  (cost=0.00..47132.93 rows=125 width=135)
> (actual time=0.542..182952.708 rows=1167810 loops=1)
>                 Filter: (data ~~ '%some text%'::text)

The problem is coming from the 125 row estimate in the above plan
fragment.  Because the number of estimated rows is low, the query
planner likely thinks a Nested Loop join is best.

What I'd do first is verify that some other join method is better by
running the query after having done:

SET enable_nestloop TO off;
<run query>
RESET enble_nestloop;

If the query then runs faster then it's going to be worth doing
something about trying to improve those statistics.

I see the like pattern matching selectivity estimation code does look
at histogram buckets, so you might have luck if you increase the
statistics targets on this column:

ALTER TABLE data ALTER COLUMN data SET STATISTICS 1000;
ANALYZE data;

The standard number of buckets is 100. The above will set it to 1000.
You can go as high as 10000, but going too high is going to slow down
the planner, so you should only go as high as you need to go.

David



Re: unoptimized nested loops

From
Jeff Janes
Date:
On Tue, May 31, 2022 at 4:04 PM Tim Kelly <gtkelly@dialectronics.com> wrote:

c_db=>select count(id) from metadata where author like '%Kelly%';

  count
-------
   3558
(1 row)

It would be interesting to see the explain of this.  We know how many rows it found, but not how many it thinks it will find.


I do not see evidence that the nested loop is trying to reduce overhead
by using the smaller set.  It seems to want to scan on data first either
way.

The planner probably doesn't know which one is smaller.
 


I have run vacuum analyze, in the hopes that the optimizer is
miscalculating, to no avail. 

What version are you using?

Cheers,

Jeff

Re: unoptimized nested loops

From
Tom Lane
Date:
Jeff Janes <jeff.janes@gmail.com> writes:
> On Tue, May 31, 2022 at 4:04 PM Tim Kelly <gtkelly@dialectronics.com> wrote:
>> I do not see evidence that the nested loop is trying to reduce overhead
>> by using the smaller set.  It seems to want to scan on data first either
>> way.

> The planner probably doesn't know which one is smaller.

There is not a lot of daylight between the cost estimates for
"a nestloop-join b" and "b nestloop-join a", if we're considering
plain seqscans on both tables and all else is equal.  It tends to
come down to factors like which one is more densely populated.

As best I can tell, the issue Tim's unhappy about is not so
much the use of a nestloop as the lack of use of any index.
But "string like '%foo%'" is not at all optimizable with a
btree index.  You might be able to get somewhere with a
pg_trgm GIN or GIST index.

            regards, tom lane



Re: unoptimized nested loops

From
Tim Kelly
Date:
Thank you to David, Jeff and Tom for your responses.  Tom's response has 
made me rethink my question.  I may have provided too much information, 
in the effort to anticipate suggestions.  Let me rephrase:

I have two tables, a parent (named "metadata") and a child (named 
"data").  Each table has two fields.  One field is shared (the "id," an 
alphanumeric field).  The other field in each table is basically the 
constraint (named "author" in metadata) and the target (named "content" 
data).  Each table has about 1.25m records/rows.  There are about 1500 
orphaned child records, but all parent records have a child record.

When I do a search, as the "human in charge (HIC)" I know that the 
constraint from the parent table will yield a very small amount of child 
table records in which the target needs to be found.  A typical search 
yields a few hundred to a few thousand parent records, which should take 
milliseconds to search for the target.  A search of all of the child 
records for the target that is then compared against the constrained 
parent records to produce a pure intersection is very inefficient.

I found discussions from ten years or more ago about where the order of 
query arguments would affect the search optimization.  Depending on the 
database, the HIC would place a known driving constraint either last or 
first in the arguments.  This practice has been reasonably abandoned as 
the default practice, but I have been unable to find how to override the 
current practice of letting the planner do the work, and the planner is 
getting it wrong.  Something that should only take one or two seconds is 
now taking three to four minutes.

So, using an even more egregious scenario I found:

c_db=>select count(id) from metadata where author like '%Tim%';

  count
-------
    261
(1 row)

Time: 650.753 ms


c_db=>select count(id) from data where data.content like '%some text%' 
and data.id in (select id from metadata where metadata.author like '%Tim%');

  count
-------
     31
(1 row)

Time: 207354.109 ms


Just as a reminder, this is 30 seconds longer than it takes to search 
the 1.25m records for the target:

c_db=> select count(id) from data where content like '%some text%';
   count
---------
  1167810
(1 row)

Time: 180144.251 ms


To address David's suggestion of turning off enable_nestloop, this 
resulted in about a 10% improvement in speed.  I found no appreciable 
difference in time by setting statistics, although there was some 
ambiguity in the suggestion.  I assume the statistics are supposed to be 
set on the content column,

ALTER TABLE data ALTER COLUMN content SET STATISTICS 1000;


To address Jeff's inquiry about planning on the smaller set:

c_db=> explain analyze select count(id) from metadata where author like 
'%Tim%';
                                                     QUERY PLAN 

------------------------------------------------------------------------------------------------------------------
  Aggregate  (cost=114040.65..114040.66 rows=1 width=11) (actual 
time=681.639..681.639 rows=1 loops=1)
    ->  Seq Scan on metadata  (cost=0.00..114040.64 rows=5 width=11) 
(actual time=3.053..681.591 rows=261 loops=1)
          Filter: ((author)::text ~~ '%Tim%'::text)
  Total runtime: 681.685 ms
(4 rows)

Time: 682.142 ms

For completeness

c_db=> explain analyze select count(id) from metadata inner join data on 
metadata.id = data.id where author like '%Tim%' and content like '%some 
text%';
                                                                 QUERY 
PLAN

-------------------------------------------------------------------------------------------------------------------------------------------
  Aggregate  (cost=48203.00..48203.01 rows=1 width=11) (actual 
time=208239.776..208239.777 rows=1 loops=1)
    ->  Nested Loop  (cost=0.00..48202.99 rows=5 width=11) (actual 
time=34102.795..208239.754 rows=31 loops=1)
          ->  Seq Scan on data  (cost=0.00..47132.93 rows=125 width=11) 
(actual time=4.714..179369.126 rows=1167810 loops=1)
                Filter: (content ~~ '%some text%'::text)
          ->  Index Scan using metadata_pkey on metadata 
(cost=0.00..8.55 rows=1 width=11) (actual time=0.024..0.024 rows=0 
loops=1167810)
                Index Cond: ((metadata.id)::text = (data.id)::text)
                Filter: ((metadata.author)::text ~~ '%Tim%'::text)
  Total runtime: 208239.847 ms
(8 rows)

Time: 208247.698 ms


As for the version

$ psql --version
psql (PostgreSQL) 8.4.1
contains support for command-line editing


Let's describe this system as "legacy" and updating is not an option. 
If the planner from this version was not optimized compared to more 
recent versions, the need for an override is even greater.  However, I 
am very reluctant to believe the version is at the heart of the problem. 
  I believe I am missing something and perhaps failing to properly 
explain my need.

How do I override the planner and instruct the computer to do what I 
say, regardless of the outcome?

Thank you,
tim

(I see I've probably provided too much information again.)

Tom Lane wrote:
> As best I can tell, the issue Tim's unhappy about is not so
> much the use of a nestloop as the lack of use of any index.
> But "string like '%foo%'" is not at all optimizable with a
> btree index.  You might be able to get somewhere with a
> pg_trgm GIN or GIST index.
> 
>             regards, tom lane



Re: unoptimized nested loops

From
Jeff Janes
Date:
On Thu, Jun 2, 2022 at 12:32 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
Jeff Janes <jeff.janes@gmail.com> writes:
> On Tue, May 31, 2022 at 4:04 PM Tim Kelly <gtkelly@dialectronics.com> wrote:
>> I do not see evidence that the nested loop is trying to reduce overhead
>> by using the smaller set.  It seems to want to scan on data first either
>> way.

> The planner probably doesn't know which one is smaller.

There is not a lot of daylight between the cost estimates for
"a nestloop-join b" and "b nestloop-join a", if we're considering
plain seqscans on both tables and all else is equal.  It tends to
come down to factors like which one is more densely populated.

As best I can tell, the issue Tim's unhappy about is not so
much the use of a nestloop as the lack of use of any index.

But it is using an index on one of the tables, on "id".  There is no reason it would not be able to reverse that, doing the seq scan on the smaller (in assumed bytes) table and using the id index on the larger (in bytes) table, to great effect.

Based on the timing of the simple counts on "data" with and without the WHERE, I'm pretty sure that what is going on here is that data.content is large and resides mostly in TOAST.  When TOAST needs to be accessed it is much slower than when it doesn't.  And that is also the cause of the estimation problem, the oversized values are just assumed to be distinct, and no histogram is generated. Without histogram boundaries to serve as a randomish sample, the selectivity estimate falls back to something even worse (pattern length), and gets it massively wrong.
 
But "string like '%foo%'" is not at all optimizable with a
btree index.  You might be able to get somewhere with a
pg_trgm GIN or GIST index.

I agree with the recommendation, but not really the reasoning.  Having the pg_trgm index on metadata.author is might be even better than just getting the planner to do the right thing without the index, but getting the planner to do the right thing even without the index would also be a big improvement over the current plan, if there were just a way to do it.  If the planner explicitly accounted for TOAST cost, that would probably do it.  Or if the selectivity estimates on data.content were better, that would too.  But Tim can't reasonably do anything about those things, while he can build the index.

Another thing he could try would be to force the correct index use by using the inner join, but writing the join condition as "on data.id = metadata.id||''"

Cheers,

Jeff

Re: unoptimized nested loops

From
Tim Kelly
Date:
I resolved the problem by eliminating the planner from the decision 
making altogether, through using a (permanently) temporary table 
populated by the subset of data records from an initial query generated 
from the metadata, then searching only in the temp table for the actual 
data records I want.  I ran this code into a function sxa ("search by 
author").  In my particular case I am looking for the same snippet of 
text over and over again so I hardwired it into the function.  The 
function uses 'like' instead of '=' on the author so I am actually 
comparing an exact match using the inner join to a pattern match in the 
function.

c_db=> select count(id) from content;
   count
---------
  1248954
(1 row)

Time: 587.325 ms

c_db=> select count(id) from data inner join metadata on data.id = 
metadata.id where author = 'Powers';
  count
-------
    347
(1 row)

Time: 519.435 ms

c_db=> select count(id) from data inner join metadata on data.id = 
metadata.id where author = 'Powers' and content like '%some text%';
  count
-------
     14
(1 row)

Time: 209895.655 ms

c_db=> select count(id) from sxa('Powers');
  count
-------
     14
(1 row)

Time: 1794.600 ms

The above function run time includes deleting the previous search 
results and creating 347 records in the temp table.  I also find that it 
appears to sometimes run even faster depending on the search (due to 
variation in content length) and can be even less than half the above time:

c_db=> select count(id) from sxa('Zelazny');
  count
-------
     13
(1 row)

Time: 790.551 ms

The inner join time run time variance of searches is greater than the 
total time for any search with the function.  Total run time for any 
inner join search was always 209 to 211 seconds, as all of the content 
values appear to be searched.  Use of a temp table reduced search time 
of 1.25m records from 3 1/2 minutes to less than two seconds and in some 
cases to less than one.

In summary, the answer to how to overcome a bad decision by the 
postgresql planner appears to be move the subset of data into a 
temporary table and force postgresql to look in it instead.  The version 
of postgresql I am using is 8.4.1, admittedly old.  If there is a newer 
version of postgresql that has fixed this, please point me to it and I 
will see if I can upgrade to it, instead of crafting functions.  Also, 
if someone could refresh my memory on how relational databases are 
supposed to work by default, I would appreciate it.  I seem to have 
gotten confused somewhere.

tim



c_db=> \d t
               Table "public.t"
  Column  |         Type          | Modifiers
---------+-----------------------+-----------
  id      | character varying(30) | not null
  content | text                  |
Indexes:
     "t_pkey" PRIMARY KEY, btree (id)

CREATE OR REPLACE FUNCTION public.sxa(author character varying)
  RETURNS TABLE(id character varying)
  LANGUAGE sql
AS $function$
delete from t;
insert into t (select id, content from metadata inner join data on 
metadata.id = data.id where author like $1);
select id from data where id in (select id from t where content like 
'%some text%');
$function$
;