Re: How come this cursor opens so slowly when called with parameters ???

From: Sybrand Bakker <postbus_at_sybrandb.demon.nl>
Date: Wed, 26 Sep 2001 18:26:10 +0200
Message-ID: <tr40guqh5q3l4c@news.demon.nl>

"Spendius" <spendius_at_MailAndNews.com> wrote in message news:2a6e94ef.0109260257.4f63e633_at_posting.google.com...
> Hi,
> I've found out something I can't understand: I have a cursor
> (named 'c_cur' below) that takes a very long time to open WHEN
> I USE IT WITH PARAMETERS (it lasts very long EVERY TIME I call
> from within the same session, not only the 1rst time); as soon
> as I remove the parameters to type the values in the WHERE
> clauses themselves, the execution of my procedure is immediate
> (I've been able to detect that it is the opening of the cursor
> that's very time-consuming, thanks to the line numbered 177
> below I can see there's a difference of 20 to 25 seconds with
> the previous DBMS_OUTPUT call -'BEGIN'-).
>
> I've drawn an TKPROF file from a session in which I ran my
> procedure 2 different ways (of which I've pasted an excerpt
> below as well), you can see that WHEN I CALL THE CURSOR WITH
> PARAMETERS IT TAKES MORE THAN 34 SECONDS in the tkprof file
> rather than 59 hundredths of seconds only above -and the EXEC
> PLAN is pretty different as well-...
>
> Does anybody please have an explanation to this behaviour ??
>
> Thanks a lot in advance...
> Regards,
> Spendius
>
> 133 -- | PROCEDURE p_train_arch_174
> 134 -- | (pin_trno_rge IN NUMBER,
> ... -- | [...])
> 145 -- | IS
> 146 -- | --CURSOR c_cur IS
> 146 -- | CURSOR c_cur (pin_trno_rge NUMBER, piv_date VARCHAR2)
> IS
> 147 -- | SELECT /*+RULE*/
> 148 -- | DISTINCT T.TRNO_RGE trno_rge,
> ... -- | [...]
> 158 -- | FROM P_TRAIN_JOUR_J_PAR_PTCAR P, TRAIN_JOUR_J T,
> STATIONS S
> 159 -- | WHERE T.DAT_DEP = TO_DATE(piv_date,'dd/mm/yyyy
> hh24:mi:ss')
> 160 -- | AND T.TRNO_RGE = pin_trno_rge
> 161 -- | AND P.TRAIN_ID = T.TRAIN_ID
> 162 -- | AND P.DAT_DEP = T.DAT_DEP
> 163 -- | AND S.PTCAR_NO = P.PTCAR_NO
> 164 -- | ORDER BY nat_rge, trno_rge, ord_no;
> 165 -- |
> 166 -- | r_cur c_cur%rowtype;
> 167 -- |
> 168 -- | l_cur_count NUMBER DEFAULT 1;
> 169 -- | BEGIN
> 170 -- | DBMS_OUTPUT.put_line('BEGIN
> '||to_char(sysdate,'dd-mm-yyyy hh24:mi:ss'));
> 171 -- | -- open c_cur;
> 171 -- | open c_cur(pin_trno_rge, piv_date);
> 172 -- | fetch c_cur into r_cur;
> 173 -- |
> 175 -- | LOOP
> 176 -- | exit when c_cur%notfound;
> 177 -- | DBMS_OUTPUT.put_line('
> -'||to_char(sysdate,'dd-mm-yyyy hh24:mi:ss'));
> ... -- | [...]
> 188 -- | fetch c_cur into r_cur;
> 189 -- | END LOOP;
> 190 -- | close c_cur;
> 191 -- | DBMS_OUTPUT.put_line('END
> '||to_char(sysdate,'dd-mm-yyyy hh24:mi:ss'));
> 192 -- | END;
>
>
>

---

---

> cursor called with values hard-coded:
>
> SELECT DISTINCT T.TRNO_RGE trno_rge,
> T.NAT_RGE AS nat_rge,
> P.ORD_NO AS ord_no,
> TO_CHAR(P.HR_ARR,'dd/mm HH24:MI:SS') AS heure_arr,
> TO_CHAR(P.HR_DEP_P,'dd/mm HH24:MI:SS') AS heure_dep,
> TRUNC(P.EH_ARR/60) AS eh_arr,
> TRUNC(P.EH_DEP/60) AS eh_dep,
> T.TRAIN_ID AS train_id,
> P.op1_cod AS op1_cod,
> P.tps_tamp AS tps_tamp,
> s.ptcar_afk AS ptcar_afk
> FROM P_TRAIN_JOUR_J_PAR_PTCAR P, TRAIN_JOUR_J T, STATIONS S
> WHERE T.DAT_DEP = TO_DATE('15/09/2001 00:00:00','dd/mm/yyyy
> hh24:mi:ss')
> AND T.TRNO_RGE = 3606
> AND P.TRAIN_ID = T.TRAIN_ID
> AND P.DAT_DEP = T.DAT_DEP
> AND S.PTCAR_NO = P.PTCAR_NO
> ORDER BY nat_rge, trno_rge, ord_no
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.07 0.24 0 0 0
> 0
> Execute 1 0.00 0.00 0 0 0
> 0
> Fetch 4 0.01 0.35 15 128 0
> 40
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 6 0.08 0.59 15 128 0
> 40
>
> Misses in library cache during parse: 1
> Optimizer goal: RULE
> Parsing user id: 59 (ARTWEB)
>
> Rows Execution Plan
> ------- ---------------------------------------------------
> 0 SELECT STATEMENT GOAL: RULE
> 40 SORT (UNIQUE)
> 40 NESTED LOOPS
> 40 NESTED LOOPS
> 40 TABLE ACCESS GOAL: ANALYZED (BY LOCAL INDEX ROWID) OF
> 'TRAIN_JOUR_J'
> 1 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TRJJ_NI2'
> (NON-UNIQUE)
> 2 TABLE ACCESS GOAL: ANALYZED (BY LOCAL INDEX ROWID) OF
> 'P_TRAIN_JOUR_J_PAR_PTCAR'
> 40 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'PTJP_UK'
> (UNIQUE)
> 41 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
> 'STATIONS'
> 40 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'STAT_UK'
> (UNIQUE)
>
>

---

---

> cursor called with values passed as parameters:
>
> SELECT DISTINCT T.TRNO_RGE TRNO_RGE,T.NAT_RGE NAT_RGE,P.ORD_NO ORD_NO,
> TO_CHAR(P.HR_ARR,'dd/mm HH24:MI:SS')
> HEURE_ARR,TO_CHAR(P.HR_DEP_P,'dd/mm
> HH24:MI:SS') HEURE_DEP,TRUNC(P.EH_ARR / 60 ) EH_ARR,TRUNC(P.EH_DEP /
> 60 )
> EH_DEP,T.TRAIN_ID TRAIN_ID,P.OP1_COD OP1_COD,P.TPS_TAMP TPS_TAMP,
> S.PTCAR_AFK PTCAR_AFK
> FROM
> P_TRAIN_JOUR_J_PAR_PTCAR P,TRAIN_JOUR_J T,STATIONS S WHERE T.DAT_DEP
> =
> TO_DATE(:b1,'dd/mm/yyyy hh24:mi:ss') AND T.TRNO_RGE = :b2 AND
> P.TRAIN_ID =
> T.TRAIN_ID AND P.DAT_DEP = T.DAT_DEP AND S.PTCAR_NO = P.PTCAR_NO
> ORDER
> BY NAT_RGE,TRNO_RGE,ORD_NO
>
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.14 2.03 0 0 0
> 0
> Execute 1 0.00 0.00 0 0 0
> 0
> Fetch 41 2.11 32.49 26 54536 3
> 40
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 43 2.25 34.52 26 54536 3
> 40
>
> Misses in library cache during parse: 1
> Optimizer goal: RULE
> Parsing user id: 59 (ARTWEB) (recursive depth: 1)
>
> Rows Execution Plan
> ------- ---------------------------------------------------
> 0 SELECT STATEMENT GOAL: RULE
> 0 SORT (UNIQUE)
> 0 NESTED LOOPS
> 0 MERGE JOIN (CARTESIAN)
> 0 TABLE ACCESS GOAL: ANALYZED (FULL) OF 'STATIONS'
> 0 SORT (JOIN)
> 0 PARTITION (SINGLE)
> 0 TABLE ACCESS GOAL: ANALYZED (BY LOCAL INDEX ROWID) OF
> 'TRAIN_JOUR_J'
> 0 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'TRJJ_NI2'
> (NON-UNIQUE)
> 0 PARTITION (SINGLE)
> 0 TABLE ACCESS GOAL: ANALYZED (BY LOCAL INDEX ROWID) OF
> 'P_TRAIN_JOUR_J_PAR_PTCAR'
> 0 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'PTJP_UK'
> (UNIQUE)
>
>

---

---

From the tkprof it seems like you want to use the *rule* based optimizer against *partitioned* tables, and you have optimized your statements for the rule based optimizer.
As the rule based optimizer doesn't support partitions at all (it was desupported in 7.0)
your rule hint was ignored and the cost-based optimizer used instead. This is one of the safest ways to create havoc as most likely you don't have statistics on your tables.
If you want to use partitions you should switch to the Cost Based Optimizer.

Regards,

Sybrand Bakker, Senior Oracle DBA Received on Wed Sep 26 2001 - 11:26:10 CDT