Query performance strangeness..

Hi Folks,

I'm new to this list, but I've been using postgresql for a few years.
In general I've been able to figure things out by reading various
docs. I've hit something now that I haven't been able to sort out at
all. It may be that there's some document that explains all this...
if so, please point it out!

I have a view called ISpacePersonRoles that joins my 'people' table
with spaces and roles:

CCOC=# \d ISpacePersonRoles
View "public.ispacepersonroles"
Column | Type | Modifiers
------------------+-----------------------+-----------
lc3key | text |
personid | character varying(40) |
last | character varying(80) |
first | character varying(40) |
middle | character varying(15) |
status | character varying(30) |
intermentspaceid | character varying(30) |
role | character varying(30) |
View definition:
SELECT lower_concat3(p."last", p."first", (p.middle::text ||
p.personid::text)::character varying) AS lc3key, p.personid,
p."last", p."first", p.middle, p.status, isp.objectid AS
intermentspaceid, isr.name AS "role"
FROM people p
LEFT JOIN intermentspacepersons isp ON p.personid::text =
isp.personid::text
LEFT JOIN intermentspaceroles isr ON isp.roleid::text =
isr.intermentspaceroleid::text;

I also have a function "get_cem_for_directBurial(personid)" that is
expensive to call, but it's also indexed, so I hoped that the index
would normally be used (essentially as a cache). It returns a
'cemetery code' so I can search for folks buried in a particular
cemetery. (The cemetery code was added to a different table after the
'people' table was more or less frozen.. I'd like to keep it that way
if possible.)

Sometimes I need to search for rows from the view that satisfy
certain criteria, sorted in some specific order. Here's where the
trouble starts. In the view I compute something I call 'lc3key',
defined as: lower_concat3(p."last", p."first", (p.middle::text ||
p.personid::text)::character varying) where 'lower_concat3' just
returns a lower case version of three strings all concatenated
together. The string is basically lastname, firstname, middle and
personid (to guarantee uniqueness). It seems like most of the time
sorting by last, first, middle should be the same as sorting by
lc3key (all of these things are indexed BTW). So here goes:

CCOC=# explain analyze select * from ISpacePersonRoles where ('STJ' =
get_cem_for_directBurial(personid) AND lc3key >= lower_concat3
('Jones', '', '') and (status = 'D' or role = 'burial') and status <>
'R' and status <> 'F') order by lc3key asc limit 100;

QUERY PLAN
------------------------------------------------------------------------
------------------------------------------------------------------------
--------------------------------
Limit (cost=1.22..1361.55 rows=100 width=62) (actual
time=2.172..90.077 rows=100 loops=1)
-> Nested Loop Left Join (cost=1.22..1157163.90 rows=85065
width=62) (actual time=2.167..89.682 rows=100 loops=1)
Join Filter: (("outer".roleid)::text =
("inner".intermentspaceroleid)::text)
Filter: ((("outer".status)::text = 'D'::text) OR
(("inner".name)::text = 'burial'::text))
-> Nested Loop Left Join (cost=0.00..1109951.60
rows=85065 width=61) (actual time=0.436..54.552 rows=374 loops=1)
-> Index Scan using idx_people_lower_concat3_last on
people p (cost=0.00..130784.91 rows=43872 width=40) (actual
time=0.366..47.016 rows=171 loops=1)
Index Cond: (lower_concat3("last", "first",
(((middle)::text || (personid)::text))::character varying) >=
'jonesAAAAAAAAAAAAAAAAAAAAAAAAA'::text)
Filter: (('STJ'::text = get_cem_for_directburial
(personid)) AND ((status)::text <> 'R'::text) AND ((status)::text <>
'F'::text))
-> Index Scan using idx_intermentspacepersons_pers
on intermentspacepersons isp (cost=0.00..22.24 rows=6 width=33)
(actual time=0.024..0.030 rows=2 loops=171)
Index Cond: (("outer".personid)::text =
(isp.personid)::text)
-> Materialize (cost=1.22..1.42 rows=20 width=19) (actual
time=0.002..0.042 rows=20 loops=374)
-> Seq Scan on intermentspaceroles isr
(cost=0.00..1.20 rows=20 width=19) (actual time=0.005..0.060 rows=20
loops=1)
Total runtime: 90.395 ms

OK.. not too bad. If I do the same query... but ask for 'HCC' rather
than 'STJ', just a different cemetery code, I get 91 seconds... about
1000 times longer!

Limit (cost=0.00..10191.16 rows=100 width=62) (actual
time=8.909..91584.430 rows=100 loops=1)
-> Nested Loop Left Join (cost=0.00..150013.78 rows=1472
width=62) (actual time=8.905..91583.951 rows=100 loops=1)
Join Filter: (("outer".roleid)::text =
("inner".intermentspaceroleid)::text)
Filter: ((("outer".status)::text = 'D'::text) OR
(("inner".name)::text = 'burial'::text))
-> Nested Loop Left Join (cost=0.00..147724.82 rows=1472
width=61) (actual time=8.824..91517.141 rows=657 loops=1)
-> Index Scan using idx_people_lower_concat3_last on
people p (cost=0.00..130784.91 rows=759 width=40) (actual
time=8.722..91396.606 rows=256 loops=1)
Index Cond: (lower_concat3("last", "first",
(((middle)::text || (personid)::text))::character varying) >=
'jonesAAAAAAAAAAAAAAAAAAAAAAAAA'::text)
Filter: (('HCC'::text = get_cem_for_directburial
(personid)) AND ((status)::text <> 'R'::text) AND ((status)::text <>
'F'::text))
-> Index Scan using idx_intermentspacepersons_pers
on intermentspacepersons isp (cost=0.00..22.24 rows=6 width=33)
(actual time=0.353..0.452 rows=3 loops=256)
Index Cond: (("outer".personid)::text =
(isp.personid)::text)
-> Seq Scan on intermentspaceroles isr (cost=0.00..1.20
rows=20 width=19) (actual time=0.003..0.047 rows=20 loops=657)
Total runtime: 91584.769 ms

Next I change the sort order of the result, just use last, first
instead of lc3key:

CCOC=# explain analyze select * from ISpacePersonRoles where ('HCC' =
get_cem_for_directBurial(personid) AND lc3key >= lower_concat3
('Jones', '', '') and (status = 'D' or role = 'burial') and status <>
'R' and status <> 'F') order by last, first asc limit 100;

QUERY PLAN
------------------------------------------------------------------------
------------------------------------------------------------------------
------------------------------------------------------------------------
-----------------------
Limit (cost=19031.87..19032.12 rows=100 width=62) (actual
time=55.845..56.418 rows=100 loops=1)
-> Sort (cost=19031.87..19035.55 rows=1472 width=62) (actual
time=55.839..56.032 rows=100 loops=1)
Sort Key: p."last", p."first"
-> Hash Left Join (cost=12.27..18954.42 rows=1472
width=62) (actual time=37.250..54.048 rows=269 loops=1)
Hash Cond: (("outer".roleid)::text =
("inner".intermentspaceroleid)::text)
Filter: ((("outer".status)::text = 'D'::text) OR
(("inner".name)::text = 'burial'::text))
-> Nested Loop Left Join (cost=11.02..18916.37
rows=1472 width=61) (actual time=0.370..44.809 rows=2157 loops=1)
-> Bitmap Heap Scan on people p
(cost=11.02..1976.46 rows=759 width=40) (actual time=0.339..14.824
rows=759 loops=1)
Recheck Cond: ('HCC'::text =
get_cem_for_directburial(personid))
Filter: ((lower_concat3("last", "first",
(((middle)::text || (personid)::text))::character varying) >=
'jonesAAAAAAAAAAAAAAAAAAAAAAAAA'::text) AND ((status)::text <>
'R'::text) AND ((status)::text <> 'F'::text))
-> Bitmap Index Scan on
idx_people_cemid (cost=0.00..11.02 rows=1433 width=0) (actual
time=0.303..0.303 rows=1415 loops=1)
Index Cond: ('HCC'::text =
get_cem_for_directburial(personid))
-> Index Scan using
idx_intermentspacepersons_pers on intermentspacepersons isp
(cost=0.00..22.24 rows=6 width=33) (actual time=0.016..0.023 rows=3
loops=759)
Index Cond: (("outer".personid)::text =
(isp.personid)::text)
-> Hash (cost=1.20..1.20 rows=20 width=19) (actual
time=0.121..0.121 rows=20 loops=1)
-> Seq Scan on intermentspaceroles isr
(cost=0.00..1.20 rows=20 width=19) (actual time=0.005..0.054 rows=20
loops=1)
Total runtime: 56.720 ms

Fine! .056 seconds! Now try 'STJ' again... using last, first:

CCOC=# explain analyze select * from ISpacePersonRoles where ('STJ' =
get_cem_for_directBurial(personid) AND lc3key >= lower_concat3
('Jones', '', '') and (status = 'D' or role = 'burial') and status <>
'R' and status <> 'F') order by last, first asc limit 100;

QUERY PLAN
------------------------------------------------------------------------
------------------------------------------------------------------------
-----------------------------------------
Limit (cost=64448.05..64448.30 rows=100 width=62) (actual
time=36866.189..36866.771 rows=100 loops=1)
-> Sort (cost=64448.05..64660.71 rows=85065 width=62) (actual
time=36866.183..36866.400 rows=100 loops=1)
Sort Key: p."last", p."first"
-> Hash Left Join (cost=49906.15..54260.22 rows=85065
width=62) (actual time=33936.104..36283.328 rows=27078 loops=1)
Hash Cond: (("outer".roleid)::text =
("inner".intermentspaceroleid)::text)
Filter: ((("outer".status)::text = 'D'::text) OR
(("inner".name)::text = 'burial'::text))
-> Merge Left Join (cost=49904.90..52132.35
rows=85065 width=61) (actual time=33913.184..35665.407 rows=107598
loops=1)
Merge Cond: ("outer"."?column6?" = "inner"."?
column4?")
-> Sort (cost=8747.88..8857.56 rows=43872
width=40) (actual time=27311.087..27414.262 rows=45700 loops=1)
Sort Key: (p.personid)::text
-> Bitmap Heap Scan on people p
(cost=808.33..4562.19 rows=43872 width=40) (actual
time=499.366..26080.114 rows=45700 loops=1)
Recheck Cond: (lower_concat3
("last", "first", (((middle)::text || (personid)::text))::character
varying) >= 'jonesAAAAAAAAAAAAAAAAAAAAAAAAA'::text)
Filter: (('STJ'::text =
get_cem_for_directburial(personid)) AND ((status)::text <> 'R'::text)
AND ((status)::text <> 'F'::text))
-> Bitmap Index Scan on
idx_people_lower_concat3_last (cost=0.00..808.33 rows=63522 width=0)
(actual time=498.285..498.285 rows=66126 loops=1)
Index Cond: (lower_concat3
("last", "first", (((middle)::text || (personid)::text))::character
varying) >= 'jonesAAAAAAAAAAAAAAAAAAAAAAAAA'::text)
-> Sort (cost=41157.02..41735.74 rows=231487
width=33) (actual time=6601.686..7115.285 rows=231484 loops=1)
Sort Key: (isp.personid)::text
-> Seq Scan on intermentspacepersons
isp (cost=0.00..5440.87 rows=231487 width=33) (actual
time=10.585..906.115 rows=231487 loops=1)
-> Hash (cost=1.20..1.20 rows=20 width=19) (actual
time=22.801..22.801 rows=20 loops=1)
-> Seq Scan on intermentspaceroles isr
(cost=0.00..1.20 rows=20 width=19) (actual time=22.668..22.717
rows=20 loops=1)
Total runtime: 36885.930 ms

Huh? How can this happen?

Where am I getting lost here?

thanks for any thoughts/input!

-steve