Home > mailing lists

Unexplained SQL behavior - Mailing list pgsql-sql

From	JOE
Subject	Unexplained SQL behavior
Date	August 18, 2002 00:07:15
Msg-id	018f01c24653$b23d8000$c801a8c0@joe Whole thread Raw
Responses	Re: Unexplained SQL behavior Re: Unexplained SQL behavior
List	pgsql-sql

Tree view

I am debugging a performance problem with a view. I have narrowed down the problem to when I adeed columns to my view.

In the examples below I have a view with 10 columns. I run an explain plan and it uses the primary key of the driver table (enrollment table) as to be expected and executes in 1.86 msec. When I added another columns (and it is a null value casted to a timestamp - LASTACCESSED) the execution plan now uses a totally different plan and now runs for 8622.16 msec. Anyone have any ideas or explination that may help understand?? --- thanks

drop view lv2 \g
create view lv2
( LEARNERID, ENROLLMENTID, GUID, EXPIREDDATE, FIRSTACCESSDATE, DISPLAYORDER,
     ASSESSMENTSSTARTED,COMPLETE, EXPIRED, TITLE ) AS
select distinct enr.learnerid, enr.enrollmentid, lov.ccguid, enr.enddate, null::timestamp without time zone,
     lov.displayorder,   'false'::character varying,   'F'::character varying,
     case when enr.endDate::timestamp without time zone > now()::timestamp without time zone then 'false' else 'true' end as "expired",
     lov.displaytitlemeid
from enrollment enr, learningObjectView lov
where enr.productid = lov.productId and not exists
        (select null
          from learnerAttendance la, learnerLaunchableAttendance lla
        where enr.enrollmentID = la.enrollmentID and la.learnerAttendanceID = lla.learnerAttendanceID and lla.launchableGUID = lov.ccGuid) \g

explain analyze select * from lv2 where enrollmentid = 21462\g
NOTICE: QUERY PLAN:

Subquery Scan lv2 (cost=264.90..264.98 rows=1 width=77) (actual time=1.53..1.61 rows=12 loops=1)
-> Unique (cost=264.90..264.98 rows=1 width=77) (actual time=1.52..1.55 rows=12 loops=1)
        -> Sort (cost=264.90..264.90 rows=3 width=77) (actual time=1.52..1.53 rows=12 loops=1)
              -> Nested Loop (cost=0.00..264.87 rows=3 width=77) (actual time=0.57..1.20 rows=12 loops=1)
                    -> Index Scan using enrollment_pk on enrollment enr (cost=0.00..3.02 rows=1 width=20) (actual time=0.21..0.21 rows=1 loops=1)
                    -> Index Scan using i_learningobjectview_productid on learningobjectview lov (cost=0.00..25.51 rows=6 width=57) (actual time=0.19..0.30 rows=13 loops=1)
                    SubPlan
                      -> Nested Loop (cost=0.00..36.69 rows=1 width=8) (actual time=0.04..0.04 rows=0 loops=13)
                            -> Index Scan using i_learnerlaunchattend_lguid on learnerlaunchableattendance lla (cost=0.00..20.19 rows=5 width=4) (actual time=0.02..0.02 rows=0 loops=13)
                            -> Index Scan using learnerattendance_pk on learnerattendance la (cost=0.00..3.02 rows=1 width=4) (actual time=0.16..0.16 rows=1 loops=1)
Total runtime: 1.86 msec

NOW I ADDED ANOTHER NULL column (LASTACCESSED field)

drop view lv2 \g
create view lv2
( LEARNERID, ENROLLMENTID, GUID, EXPIREDDATE, FIRSTACCESSDATE, LASTACCESSED, DISPLAYORDER,
    ASSESSMENTSSTARTED,COMPLETE, EXPIRED, TITLE ) AS
select distinct enr.learnerid, enr.enrollmentid, lov.ccguid, enr.enddate, null::timestamp without time zone, null::timestamp without time zone,
    lov.displayorder,   'false'::character varying,   'F'::character varying,
     case when enr.endDate::timestamp without time zone > now()::timestamp without time zone then 'false' else 'true' end as "expired",
     lov.displaytitlemeid
from enrollment enr, learningObjectView lov
where enr.productid = lov.productId and not exists
        (select null
          from learnerAttendance la, learnerLaunchableAttendance lla
        where enr.enrollmentID = la.enrollmentID and la.learnerAttendanceID = lla.learnerAttendanceID and lla.launchableGUID = lov.ccGuid) \g

explain analyze select * from lv2 where enrollmentid = 21462\g

NOTICE: QUERY PLAN:

Subquery Scan lv2 (cost=1968402.36..1969071.62 rows=2677 width=77) (actual time=8273.16..8516.75 rows=12 loops=1)
-> Unique (cost=1968402.36..1969071.62 rows=2677 width=77) (actual time=8273.08..8458.33 rows=63048 loops=1)
        -> Sort (cost=1968402.36..1968402.36 rows=26770 width=77) (actual time=8273.07..8343.14 rows=63048 loops=1)
              -> Merge Join (cost=0.00..1965714.31 rows=26770 width=77) (actual time=1.28..7226.99 rows=63048 loops=1)
                    -> Index Scan using i_enrollment_product on enrollment enr (cost=0.00..608.96 rows=8746 width=20) (actual time=0.17..54.26 rows=8746 loops=1)
                    -> Index Scan using i_learningobjectview_productid on learningobjectview lov (cost=0.00..207.57 rows=3278 width=57) (actual time=0.15..333.79 rows=67003 loops=1)
                    SubPlan
                      -> Nested Loop (cost=0.00..36.69 rows=1 width=8) (actual time=0.09..0.09 rows=0 loops=64942)
                            -> Index Scan using i_learnerlaunchattend_lguid on learnerlaunchableattendance lla (cost=0.00..20.19 rows=5 width=4) (actual time=0.01..0.03 rows=5 loops=64942)
                            -> Index Scan using learnerattendance_pk on learnerattendance la (cost=0.00..3.02 rows=1 width=4) (actual time=0.01..0.01 rows=0 loops=309102)
Total runtime: 8622.16 msec

pgsql-sql by date:

From: Bruce Momjian
Date: 17 August 2002, 10:21:25
Subject: Re: Difference between is true and = 't' in boolean feild. & bitmap

From: Tom Lane
Date: 18 August 2002, 00:55:40
Subject: Re: Unexplained SQL behavior

Unexplained SQL behavior - Mailing list pgsql-sql

Previous

Next