Re: oddly slow query

Hello.

Thanks for the replies.

Pavel Stehule wrote:
> what do you do in x_program function? Are you sure so it is fast?
>
I do not think the function is the problem, as running the slow query
without it is just as slow, and similar queries using that function are
quick.

Tom Lane wrote:
>
> Let's see the *whole* EXPLAIN ANALYZE output for all three of the
> queries you mentioned.
Sorry for not including more.
Here are the 3 EXPLAIN ANALYZE commands followed by the output:

explain analyze select count(*) from clinical_reg_current LEFT JOIN
client using (client_id) WHERE
tier_program(clinical_reg_current.benefit_type_code) = 'SAGE';


QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=8969.16..8969.17 rows=1 width=0) (actual
time=738140.818..738140.820 rows=1 loops=1)
-> Nested Loop Left Join (cost=755.61..8968.29 rows=346 width=0)
(actual time=150.918..738137.244 rows=684 loops=1)
Join Filter: (clinical_reg_current.client_id = client.client_id)
-> Subquery Scan clinical_reg_current (cost=754.36..758.23
rows=1 width=4) (actual time=57.359..146.717 rows=684 loops=1)
Filter: (tier_program(benefit_type_code) = 'SAGE'::text)
-> Unique (cost=754.36..756.47 rows=117 width=211)
(actual time=56.427..67.998 rows=1000 loops=1)
-> Sort (cost=754.36..755.42 rows=422 width=211)
(actual time=56.419..60.020 rows=1003 loops=1)
Sort Key: tbl_clinical_reg.client_id,
tbl_clinical_reg.clinical_reg_date
-> Seq Scan on tbl_clinical_reg
(cost=0.00..735.96 rows=422 width=211) (actual time=7.447..52.914
rows=1003 loops=1)
Filter: ((NOT is_deleted) AND
(clinical_reg_date <= ('now'::text)::date) AND ((clinical_reg_date_end
>= ('now'::text)::date) OR (clinical_reg_date_end IS NULL)) AND
((kc_authorization_status_code)::text <> ALL (('{CX,TM}'::character
varying[])::text[])) AND ((benefit_type_code)::text <> ALL
(('{75,98,99,00}'::character varying[])::text[])))
-> Hash Left Join (cost=1.25..6653.69 rows=69172 width=632)
(actual time=0.025..925.160 rows=69179 loops=684)
Hash Cond: (tbl_client.client_id = prot.client_id)
-> Seq Scan on tbl_client (cost=0.00..3453.20
rows=69172 width=427) (actual time=0.012..221.612 rows=69179 loops=684)
Filter: (NOT is_deleted)
-> Hash (cost=1.20..1.20 rows=4 width=209) (actual
time=0.172..0.172 rows=4 loops=1)
-> Subquery Scan prot (cost=1.14..1.20 rows=4
width=209) (actual time=0.111..0.153 rows=4 loops=1)
-> Unique (cost=1.14..1.16 rows=4
width=162) (actual time=0.103..0.128 rows=4 loops=1)
-> Sort (cost=1.14..1.15 rows=4
width=162) (actual time=0.099..0.106 rows=4 loops=1)
Sort Key:
tbl_client_protected.client_id, tbl_client_protected.client_protected_date
-> Seq Scan on
tbl_client_protected (cost=0.00..1.10 rows=4 width=162) (actual
time=0.039..0.061 rows=4 loops=1)
Filter: ((NOT is_deleted)
AND (client_protected_date <= ('now'::text)::date) AND
((client_protected_date_end > ('now'::text)::date) OR
(client_protected_date_end IS NULL)))
Total runtime: 738142.119 ms
(22 rows)

---------------------------------------------------------------
explain analyze select count(*) from clinical_reg_current LEFT JOIN
client using (client_id);


QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=10485.44..10485.45 rows=1 width=0) (actual
time=1497.870..1497.872 rows=1 loops=1)
-> Hash Left Join (cost=8964.43..10384.27 rows=40466 width=0)
(actual time=1482.614..1495.678 rows=1000 loops=1)
Hash Cond: (clinical_reg_current.client_id = client.client_id)
-> Unique (cost=754.36..756.47 rows=117 width=211) (actual
time=59.971..66.819 rows=1000 loops=1)
-> Sort (cost=754.36..755.42 rows=422 width=211)
(actual time=59.963..62.183 rows=1003 loops=1)
Sort Key: tbl_clinical_reg.client_id,
tbl_clinical_reg.clinical_reg_date
-> Seq Scan on tbl_clinical_reg
(cost=0.00..735.96 rows=422 width=211) (actual time=6.604..56.440
rows=1003 loops=1)
Filter: ((NOT is_deleted) AND
(clinical_reg_date <= ('now'::text)::date) AND ((clinical_reg_date_end
>= ('now'::text)::date) OR (clinical_reg_date_end IS NULL)) AND
((kc_authorization_status_code)::text <> ALL (('{CX,TM}'::character
varying[])::text[])) AND ((benefit_type_code)::text <> ALL
(('{75,98,99,00}'::character varying[])::text[])))
-> Hash (cost=7345.41..7345.41 rows=69172 width=4) (actual
time=1422.563..1422.563 rows=69179 loops=1)
-> Subquery Scan client (cost=1.25..7345.41 rows=69172
width=4) (actual time=0.282..1240.906 rows=69179 loops=1)
-> Hash Left Join (cost=1.25..6653.69 rows=69172
width=632) (actual time=0.275..940.975 rows=69179 loops=1)
Hash Cond: (tbl_client.client_id =
prot.client_id)
-> Seq Scan on tbl_client
(cost=0.00..3453.20 rows=69172 width=427) (actual time=0.019..227.016
rows=69179 loops=1)
Filter: (NOT is_deleted)
-> Hash (cost=1.20..1.20 rows=4 width=209)
(actual time=0.179..0.179 rows=4 loops=1)
-> Subquery Scan prot
(cost=1.14..1.20 rows=4 width=209) (actual time=0.100..0.152 rows=4 loops=1)
-> Unique (cost=1.14..1.16
rows=4 width=162) (actual time=0.089..0.119 rows=4 loops=1)
-> Sort (cost=1.14..1.15
rows=4 width=162) (actual time=0.085..0.093 rows=4 loops=1)
Sort Key:
tbl_client_protected.client_id, tbl_client_protected.client_protected_date
-> Seq Scan on
tbl_client_protected (cost=0.00..1.10 rows=4 width=162) (actual
time=0.031..0.058 rows=4 loops=1)
Filter: ((NOT
is_deleted) AND (client_protected_date <= ('now'::text)::date) AND
((client_protected_date_end > ('now'::text)::date) OR
(client_protected_date_end IS NULL)))
Total runtime: 1498.442 ms
(22 rows)

---------------------------------------------------

explain analyze select count(*) from clinical_reg_current WHERE
tier_program(clinical_reg_current.benefit_type_code) = 'SAGE'


QUERY PLAN

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=758.23..758.24 rows=1 width=0) (actual
time=90.335..90.337 rows=1 loops=1)
-> Subquery Scan clinical_reg_current (cost=754.36..758.23 rows=1
width=0) (actual time=51.892..88.528 rows=684 loops=1)
Filter: (tier_program(benefit_type_code) = 'SAGE'::text)
-> Unique (cost=754.36..756.47 rows=117 width=211) (actual
time=51.355..58.708 rows=1000 loops=1)
-> Sort (cost=754.36..755.42 rows=422 width=211)
(actual time=51.349..53.521 rows=1003 loops=1)
Sort Key: tbl_clinical_reg.client_id,
tbl_clinical_reg.clinical_reg_date
-> Seq Scan on tbl_clinical_reg
(cost=0.00..735.96 rows=422 width=211) (actual time=6.361..48.347
rows=1003 loops=1)
Filter: ((NOT is_deleted) AND
(clinical_reg_date <= ('now'::text)::date) AND ((clinical_reg_date_end
>= ('now'::text)::date) OR (clinical_reg_date_end IS NULL)) AND
((kc_authorization_status_code)::text <> ALL (('{CX,TM}'::character
varying[])::text[])) AND ((benefit_type_code)::text <> ALL
(('{75,98,99,00}'::character varying[])::text[])))
Total runtime: 90.452 ms
(9 rows)

> It would also be appropriate to mention
> exactly which PG version you're using.
>
Version is 8.2.5.

Thanks,
jessi
--
Jessi Berkelhammer
Downtown Emergency Service Center
Computer Programming Specialist