Laurenz Albe wrote:

> Antonio Batovanja wrote:
>> I'm having trouble understanding, why a specific query on a small
>> database is taking so long...
>>
>
> Before I try to understand the execution plans:
>
> Have you run ANALYZE on the tables involved before you ran the query?

Hi,

Just to be on the safe side, I've run ANALYZE now.
Here are the query plans for the two queries:

1) the slooooow query:
EXPLAIN ANALYZE SELECT DISTINCT ldap_entries.id, organization.id,
text('organization') AS objectClass, ldap_entries.dn AS dn FROM
ldap_entries, organization, ldap_entry_objclasses WHERE
organization.id=ldap_entries.keyval AND ldap_entries.oc_map_id=1 AND
upper(ldap_entries.dn) LIKE '%DC=HUMANOMED,DC=AT' AND 1=1 OR
(ldap_entries.id=ldap_entry_objclasses.entry_id AND
ldap_entry_objclasses.oc_name='organization');

QUERY PLAN
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
------
Unique (cost=319470.73..319470.97 rows=19 width=74) (actual
time=96354.150..96452.492 rows=1 loops=1)
-> Sort (cost=319470.73..319470.78 rows=19 width=74) (actual
time=96354.136..96383.958 rows=5928 loops=1)
Sort Key: ldap_entries.id, organization.id, 'organization'::text,
ldap_entries.dn
-> Nested Loop (cost=56.33..319470.33 rows=19 width=74) (actual
time=0.088..96086.902 rows=5928 loops=1)
Join Filter: ((("inner".id = "inner".keyval) AND
("inner".oc_map_id = 1) AND (upper(("inner".dn)::text) ~~
'%DC=HUMANOMED,DC=AT'::text)) OR (("inner".id = "outer".entry_id) AND
(("outer".oc_name)::text = 'organization'::text)))
-> Seq Scan on ldap_entry_objclasses (cost=0.00..102.28
rows=5928 width=20) (actual time=0.012..39.040 rows=5928 loops=1)
-> Materialize (cost=56.33..71.72 rows=1539 width=82)
(actual time=0.005..7.786 rows=1539 loops=5928)
-> Nested Loop (cost=0.00..54.79 rows=1539 width=82)
(actual time=0.033..26.661 rows=1539 loops=1)
-> Seq Scan on organization (cost=0.00..1.01
rows=1 width=4) (actual time=0.006..0.013 rows=1 loops=1)
-> Seq Scan on ldap_entries (cost=0.00..38.39
rows=1539 width=78) (actual time=0.010..9.845 rows=1539 loops=1)
Total runtime: 96453.293 ms
(11 rows)


2) The fast query - just replaced OR with UNION:
EXPLAIN ANALYZE SELECT DISTINCT ldap_entries.id, organization.id,
text('organization') AS objectClass, ldap_entries.dn AS dn FROM
ldap_entries, organization, ldap_entry_objclasses WHERE
organization.id=ldap_entries.keyval AND ldap_entries.oc_map_id=1 AND
upper(ldap_entries.dn) LIKE '%DC=HUMANOMED,DC=AT' AND 1=1
UNION SELECT DISTINCT ldap_entries.id, organization.id, text('organization')
AS objectClass, ldap_entries.dn AS dn FROM ldap_entries, organization,
ldap_entry_objclasses WHERE (ldap_entries.id=ldap_entry_objclasses.entry_id
AND ldap_entry_objclasses.oc_name='organization');

QUERY PLAN
-------------------------------------------------------------------------------
-------------------------------------------------------------------------------
-----------------------
Unique (cost=728.39..728.64 rows=20 width=74) (actual
time=463.587..463.602 rows=1 loops=1)
-> Sort (cost=728.39..728.44 rows=20 width=74) (actual
time=463.577..463.582 rows=1 loops=1)
Sort Key: id, id, objectclass, dn
-> Append (cost=537.13..727.95 rows=20 width=74) (actual
time=364.814..463.549 rows=1 loops=1)
-> Subquery Scan "*SELECT* 1" (cost=537.13..611.24 rows=1
width=74) (actual time=364.804..463.357 rows=1 loops=1)
-> Unique (cost=537.13..611.23 rows=1 width=74)
(actual time=364.790..463.331 rows=1 loops=1)
-> Sort (cost=537.13..551.95 rows=5928
width=74) (actual time=364.778..394.740 rows=5928 loops=1)
Sort Key: ldap_entries.id, organization.id,
'organization'::text, ldap_entries.dn
-> Nested Loop (cost=0.00..165.64
rows=5928 width=74) (actual time=0.097..96.368 rows=5928 loops=1)
-> Nested Loop (cost=0.00..4.08
rows=1 width=74) (actual time=0.073..0.107 rows=1 loops=1)
-> Seq Scan on organization
(cost=0.00..1.01 rows=1 width=4) (actual time=0.013..0.020 rows=1 loops=1)
-> Index Scan using
ldap_entries_key_idx on ldap_entries (cost=0.00..3.06 rows=1 width=74)
(actual time=0.042..0.054 rows=1 loops=1)
Index Cond: ("outer".id =
ldap_entries.keyval)
Filter: ((oc_map_id = 1)
AND (upper((dn)::text) ~~ '%DC=HUMANOMED,DC=AT'::text))
-> Seq Scan on ldap_entry_objclasses
(cost=0.00..102.28 rows=5928 width=0) (actual time=0.006..31.622 rows=5928
loops=1)
-> Subquery Scan "*SELECT* 2" (cost=116.29..116.71 rows=19
width=74) (actual time=0.167..0.167 rows=0 loops=1)
-> Unique (cost=116.29..116.52 rows=19 width=74)
(actual time=0.156..0.156 rows=0 loops=1)
-> Sort (cost=116.29..116.33 rows=19 width=74)
(actual time=0.145..0.145 rows=0 loops=1)
Sort Key: ldap_entries.id, organization.id,
'organization'::text, ldap_entries.dn
-> Nested Loop (cost=63.62..115.88
rows=19 width=74) (actual time=0.117..0.117 rows=0 loops=1)
-> Seq Scan on organization
(cost=0.00..1.01 rows=1 width=4) (actual time=0.013..0.018 rows=1 loops=1)
-> Merge Join (cost=63.62..114.68
rows=19 width=70) (actual time=0.074..0.074 rows=0 loops=1)
Merge Cond: ("outer".id =
"inner".entry_id)
-> Index Scan using
ldap_entries_pkey on ldap_entries (cost=0.00..46.93 rows=1539 width=70)
(actual time=0.019..0.019 rows=1 loops=1)
-> Sort (cost=63.62..63.67
rows=19 width=4) (actual time=0.040..0.040 rows=0 loops=1)
Sort Key:
ldap_entry_objclasses.entry_id
-> Index Scan using xxxx
on ldap_entry_objclasses (cost=0.00..63.22 rows=19 width=4) (actual
time=0.027..0.027 rows=0 loops=1)
Index Cond:
((oc_name)::text = 'organization'::text)
Total runtime: 464.189 ms
(29 rows)



I know the output doesn't look nice, but wrapping at 80 characters is a must
for newsgroups...

Thank you all in advance,
Toni