1 2 Previous Next 24 Replies Latest reply: Oct 7, 2010 2:42 PM by Jonathan Lewis Go to original post RSS
      • 15. Re: high consistent read during parse call | tkprof output
        PAB
        When this question came in to my mind, in next second one name came in my mind to clear this. And that is "Jonathan Lewis"

        In-fact, I search your blog also to find out clue but I didn't succeed . And then I decide to post this on OTN.

        Thanks JL.

        Thanks to Hemant and others for sharing knowledge.
        • 16. Re: high consistent read during parse call | tkprof output
          Charles Hooper
          PAB wrote:
          Hello all,

          Platform:- Oracle 10.2.0 on windows 32 bit

          I want your help to understand following trace file.
          If you look at this trace file there is high number of consistent read block for prase call. I want to know why Oracle go for this much of consistent read for parse call?
          select u.DISPLAY_NAME,u.PASSWORD,u.user_type 
          FROM
          USER_ACCOUNT u,STATUS s WHERE u.status_id=s.status_id and 
          Lower(u.DISPLAY_NAME) like Lower('admin') and s.STATUS_NAME='Available'
          
          
          call     count       cpu    elapsed       disk      query    current        rows
          ------- ------  -------- ---------- ---------- ---------- ----------  ----------
          Parse        4      0.85       1.07          0       3599          0           0
          Execute      4      0.00       0.00          0          0          0           0
          Fetch        4      0.01       0.05         14         36          0           4
          ------- ------  -------- ---------- ---------- ---------- ----------  ----------
          total       12      0.86       1.13         14       3635          0           4
          
          Misses in library cache during parse: 4
          Optimizer mode: ALL_ROWS
          Parsing user id: 72  
          
          Rows     Row Source Operation
          -------  ---------------------------------------------------
          1  NESTED LOOPS  (cr=9 pr=8 pw=0 time=33821 us)
          1   TABLE ACCESS BY INDEX ROWID STATUS (cr=2 pr=2 pw=0 time=21787 us)
          1    INDEX UNIQUE SCAN STATUS_CON21 (cr=1 pr=1 pw=0 time=20957 us)(object id 58618)
          1   TABLE ACCESS FULL USER_ACCOUNT (cr=7 pr=6 pw=0 time=11978 us) 
          Thanks.
          I do not believe that anyone has mentioned the consistent gets on the hard parse possibly being caused by dynamic sampling.
          SHOW PARAMETER DYNAMIC_SAMPLING
           
          NAME                                 TYPE        VALUE
          ------------------------------------ ----------- -----
          optimizer_dynamic_sampling           integer     2
          The above is the default starting with Oracle database 10.1. Now a quick test case to demonstrate:
          CREATE TABLE T1 (
            C1 NUMBER NOT NULL,
            C2 VARCHAR2(20) NOT NULL,
            C3 VARCHAR2(100));
           
          CREATE INDEX IND_T1_C1 ON T1(C1);
          CREATE INDEX IND_T1_C2 ON T1(C2);
           
          CREATE TABLE T2 (
            C1 NUMBER NOT NULL,
            C2 VARCHAR2(20) NOT NULL,
            C3 VARCHAR2(100));
           
          CREATE INDEX IND_T2_C1 ON T2(C1);
          CREATE INDEX IND_T2_C2 ON T2(C2);
          The above creates two simple tables, each with two indexes. Note that the indexes are created before the tables contain any rows, so statistics are not automatically collected for the indexes when they are created. Now to insert the rows:
          INSERT INTO
            T1
          SELECT
            ROWNUM,
            RPAD(TO_CHAR(ROWNUM),20,'A'),
            RPAD(TO_CHAR(ROWNUM),100,'B')
          FROM
            DUAL
          CONNECT BY
            LEVEL<=100000;
           
          COMMIT;
           
          INSERT INTO
            T2
          SELECT
            *
          FROM
            T1;
           
          COMMIT;
          Just to verify that the indexes do not have statistics:
          COLUMN INDEX_NAME FORMAT A10
           
          SELECT
            INDEX_NAME,
            BLEVEL,
            NUM_ROWS,
            LEAF_BLOCKS
          FROM
            USER_INDEXES
          WHERE
            INDEX_NAME IN ('IND_T1_C1','IND_T2_C1','IND_T1_C2','IND_T2_C2');
           
          INDEX_NAME     BLEVEL   NUM_ROWS LEAF_BLOCKS
          ---------- ---------- ---------- -----------
          IND_T1_C1
          IND_T1_C2
          IND_T2_C1
          IND_T2_C2
          Now for the test (on Oracle Database 11.1.0.7):
          ALTER SESSION SET TRACEFILE_IDENTIFIER = 'PARSE_TEST1';
          ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 1';
           
          SET AUTOTRACE TRACEONLY STATISTICS
          
          SELECT /* PARSE_TEST1 */
            T1.C1 T1_C1,
            SUBSTR(T1.C3,1,10) T1_C3,
            T2.C2 T2_C2,
            SUBSTR(T2.C3,1,10) T2_C3
          FROM
            T1,
            T2
          WHERE
            T1.C1=T2.C1
            AND T1.C1<=2000;
           
          Statistics
          ---------------------------------------------------
                   17  recursive calls
                    0  db block gets
                  514  consistent gets
                   15  physical reads
                    0  redo size
               113831  bytes sent via SQL*Net to client
                 1844  bytes received via SQL*Net from client
                  135  SQL*Net roundtrips to/from client
                    2  sorts (memory)
                    0  sorts (disk)
                 2000  rows processed
          Note in the above that there were 514 consistent gets to retrieve 2,000 rows (15 rows at a time).

          Continuing with the test:
          ALTER SESSION SET TRACEFILE_IDENTIFIER = 'PARSE_TEST2';
           
          SELECT /* PARSE_TEST2 */
            T1.C1 T1_C1,
            SUBSTR(T1.C3,1,10) T1_C3,
            T2.C2 T2_C2,
            SUBSTR(T2.C3,1,10) T2_C3
          FROM
            T1,
            T2
          WHERE
            T1.C1=T2.C1
            AND T1.C1 BETWEEN 2001 AND 4000;
           
          Statistics
          ---------------------------------------------------
                   17  recursive calls
                    0  db block gets
                  560  consistent gets
                   79  physical reads
                 3276  redo size
               113930  bytes sent via SQL*Net to client
                 1844  bytes received via SQL*Net from client
                  135  SQL*Net roundtrips to/from client
                    2  sorts (memory)
                    0  sorts (disk)
                 2000  rows processed
          Note in the above that there were 560 consistent gets to retrieve 2,000 rows.

          Continuing with the test:
          ALTER SESSION SET TRACEFILE_IDENTIFIER = 'PARSE_TEST3';
           
          SELECT /* PARSE_TEST3 */
            T1.C1 T1_C1,
            SUBSTR(T1.C3,1,10) T1_C3,
            T2.C2 T2_C2,
            SUBSTR(T2.C3,1,10) T2_C3
          FROM
            T1,
            T2
          WHERE
            T1.C1=T2.C1
            AND T1.C1 BETWEEN 4001 AND 6000;
           
          Statistics
          ---------------------------------------------------
                   13  recursive calls
                    0  db block gets
                  568  consistent gets
                  102  physical reads
                 3564  redo size
               113930  bytes sent via SQL*Net to client
                 1844  bytes received via SQL*Net from client
                  135  SQL*Net roundtrips to/from client
                    2  sorts (memory)
                    0  sorts (disk)
                 2000  rows processed
          Note in the above that there were 568 consistent gets to retrieve 2,000 rows.

          Continuing with the test:
          ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF';
           
          SELECT /* PARSE_TEST3 */
            T1.C1 T1_C1,
            SUBSTR(T1.C3,1,10) T1_C3,
            T2.C2 T2_C2,
            SUBSTR(T2.C3,1,10) T2_C3
          FROM
            T1,
            T2
          WHERE
            T1.C1=T2.C1
            AND T1.C1 BETWEEN 4001 AND 6000;
           
          Statistics
          ---------------------------------------------------
                   17  recursive calls
                    0  db block gets
                  520  consistent gets
                    8  physical reads
                    0  redo size
               113930  bytes sent via SQL*Net to client
                 1844  bytes received via SQL*Net from client
                  135  SQL*Net roundtrips to/from client
                    2  sorts (memory)
                    0  sorts (disk)
                 2000  rows processed
          Note that in the above there was another hard parse.

          Now let's take a look in the trace files, starting with the PARSE_TEST1 trace file (note that I manually line wrapped the dep=1 SQL statements):
          ...
          =====================
          PARSING IN CURSOR #4 len=619 dep=1 uid=60 oct=3 lid=60 tim=517854252962 hv=1052836258 ad='224c0738' sqlid='dwa1q5szc20d2'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled',
           'false') NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_00"), NVL(SUM(C2),:"SYS_B_01"), COUNT(DISTINCT C3),
           NVL(SUM(CASE WHEN C3 IS NULL THEN :"SYS_B_02" ELSE :"SYS_B_03" END),:"SYS_B_04") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE
           NO_PARALLEL("T1") FULL("T1") NO_PARALLEL_INDEX("T1") */ :"SYS_B_05" AS C1, CASE WHEN "T1"."C1"<=:"SYS_B_06" THEN :"SYS_B_07"
           ELSE :"SYS_B_08" END AS C2, "T1"."C1" AS C3 FROM "T1" SAMPLE BLOCK (:"SYS_B_09" , :"SYS_B_10") SEED (:"SYS_B_11") "T1") SAMPLESUB
          END OF STMT
          PARSE #4:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=517854252962
          EXEC #4:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=3906273573,tim=517854252962
          FETCH #4:c=0,e=0,p=0,cr=71,cu=0,mis=0,r=1,dep=1,og=1,plh=3906273573,tim=517854252962
          STAT #4 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT GROUP BY (cr=71 pr=0 pw=0 time=0 us)'
          STAT #4 id=2 cnt=3410 pid=1 pos=1 obj=102003 op='TABLE ACCESS SAMPLE T1 (cr=71 pr=0 pw=0 time=0 us cost=2 size=75 card=3)'
          CLOSE #4:c=0,e=0,dep=1,type=0,tim=517854252962
          =====================
          PARSING IN CURSOR #2 len=445 dep=1 uid=60 oct=3 lid=60 tim=517854252962 hv=840679737 ad='285dce70' sqlid='2r4a0g8t1rh9t'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB)
           NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM
           (SELECT /*+ NO_PARALLEL("T1") INDEX("T1" IND_T1_C1) NO_PARALLEL_INDEX("T1") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3
            FROM "T1" "T1" WHERE "T1"."C1"<=:"SYS_B_6" AND ROWNUM <= :"SYS_B_7") SAMPLESUB
          END OF STMT
          PARSE #2:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=517854252962
          EXEC #2:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=311010773,tim=517854252962
          FETCH #2:c=0,e=0,p=0,cr=5,cu=0,mis=0,r=1,dep=1,og=1,plh=311010773,tim=517854252962
          STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=5 pr=0 pw=0 time=0 us)'
          STAT #2 id=2 cnt=2000 pid=1 pos=1 obj=0 op='VIEW  (cr=5 pr=0 pw=0 time=0 us cost=12 size=390 card=10)'
          STAT #2 id=3 cnt=2000 pid=2 pos=1 obj=0 op='COUNT STOPKEY (cr=5 pr=0 pw=0 time=0 us)'
          STAT #2 id=4 cnt=2000 pid=3 pos=1 obj=102004 op='INDEX RANGE SCAN IND_T1_C1 (cr=5 pr=0 pw=0 time=0 us cost=12 size=429 card=33)'
          CLOSE #2:c=0,e=0,dep=1,type=0,tim=517854252962
          =====================
          PARSING IN CURSOR #6 len=619 dep=1 uid=60 oct=3 lid=60 tim=517854252962 hv=3874662801 ad='224bb3a0' sqlid='0qdcdrrmg5acj'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')
           NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_00"), NVL(SUM(C2),:"SYS_B_01"), COUNT(DISTINCT C3),
           NVL(SUM(CASE WHEN C3 IS NULL THEN :"SYS_B_02" ELSE :"SYS_B_03" END),:"SYS_B_04") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("T2")
           FULL("T2") NO_PARALLEL_INDEX("T2") */ :"SYS_B_05" AS C1, CASE WHEN "T2"."C1"<=:"SYS_B_06" THEN :"SYS_B_07" ELSE :"SYS_B_08" END AS C2,
           "T2"."C1" AS C3 FROM "T2" SAMPLE BLOCK (:"SYS_B_09" , :"SYS_B_10") SEED (:"SYS_B_11") "T2") SAMPLESUB
          END OF STMT
          PARSE #6:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=517854252962
          EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=724732973,tim=517854252962
          FETCH #6:c=0,e=31245,p=15,cr=71,cu=0,mis=0,r=1,dep=1,og=1,plh=724732973,tim=517854284207
          STAT #6 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT GROUP BY (cr=71 pr=15 pw=0 time=0 us)'
          STAT #6 id=2 cnt=3420 pid=1 pos=1 obj=102006 op='TABLE ACCESS SAMPLE T2 (cr=71 pr=15 pw=0 time=0 us cost=2 size=75 card=3)'
          CLOSE #6:c=0,e=0,dep=1,type=0,tim=517854284207
          =====================
          PARSING IN CURSOR #5 len=445 dep=1 uid=60 oct=3 lid=60 tim=517854284207 hv=2421073910 ad='1f4973fc' sqlid='b84x6ja84x9zq'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB)
           NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM (SELECT /*+ NO_PARALLEL("T2")
           INDEX("T2" IND_T2_C1) NO_PARALLEL_INDEX("T2") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3  FROM "T2" "T2" WHERE
           "T2"."C1"<=:"SYS_B_6" AND ROWNUM <= :"SYS_B_7") SAMPLESUB
          END OF STMT
          PARSE #5:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=0,tim=517854284207
          EXEC #5:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=1,plh=1821698049,tim=517854284207
          FETCH #5:c=0,e=0,p=0,cr=8,cu=0,mis=0,r=1,dep=1,og=1,plh=1821698049,tim=517854284207
          STAT #5 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=8 pr=0 pw=0 time=0 us)'
          STAT #5 id=2 cnt=2000 pid=1 pos=1 obj=0 op='VIEW  (cr=8 pr=0 pw=0 time=0 us cost=12 size=390 card=10)'
          STAT #5 id=3 cnt=2000 pid=2 pos=1 obj=0 op='COUNT STOPKEY (cr=8 pr=0 pw=0 time=0 us)'
          STAT #5 id=4 cnt=2000 pid=3 pos=1 obj=102007 op='INDEX RANGE SCAN IND_T2_C1 (cr=8 pr=0 pw=0 time=0 us cost=12 size=429 card=33)'
          CLOSE #5:c=0,e=0,dep=1,type=0,tim=517854284207
          =====================
          PARSING IN CURSOR #3 len=163 dep=0 uid=60 oct=3 lid=60 tim=517854284207 hv=701515739 ad='1f4849dc' sqlid='dr1pvrsnx0jyv'
          SELECT /* PARSE_TEST1 */
            T1.C1 T1_C1,
            SUBSTR(T1.C3,1,10) T1_C3,
            T2.C2 T2_C2,
            SUBSTR(T2.C3,1,10) T2_C3
          FROM
            T1,
            T2
          WHERE
            T1.C1=T2.C1
            AND T1.C1<=2000
          END OF STMT
          PARSE #3:c=0,e=31245,p=15,cr=159,cu=0,mis=1,r=0,dep=0,og=1,plh=169351222,tim=517854284207
          EXEC #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=169351222,tim=517854284207
          FETCH #3:c=15625,e=31263,p=0,cr=45,cu=0,mis=0,r=1,dep=0,og=1,plh=169351222,tim=517854315470
          FETCH #3:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=15,dep=0,og=1,plh=169351222,tim=517854315470
          ...
          FETCH #3:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=4,dep=0,og=1,plh=169351222,tim=517854346714
          STAT #3 id=1 cnt=2000 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=355 pr=0 pw=0 time=0 us cost=48 size=284000 card=2000)'
          STAT #3 id=2 cnt=2000 pid=1 pos=1 obj=102003 op='TABLE ACCESS BY INDEX ROWID T1 (cr=42 pr=0 pw=0 time=0 us cost=22 size=130000 card=2000)'
          STAT #3 id=3 cnt=2000 pid=2 pos=1 obj=102004 op='INDEX RANGE SCAN IND_T1_C1 (cr=5 pr=0 pw=0 time=0 us cost=6 size=0 card=2000)'
          STAT #3 id=4 cnt=2000 pid=1 pos=2 obj=102006 op='TABLE ACCESS BY INDEX ROWID T2 (cr=313 pr=0 pw=0 time=0 us cost=25 size=154000 card=2000)'
          STAT #3 id=5 cnt=2000 pid=4 pos=1 obj=102007 op='INDEX RANGE SCAN IND_T2_C1 (cr=142 pr=0 pw=0 time=0 us cost=9 size=0 card=2000)'
          In the above, you will notice that the parse call for our SQL statement performed 159 consistent gets. If you add up the number of consistent gets performed by the dep=1 SQL statements that immediately preceed our SQL statement (71 + 5 + 71 + 8), you can see where 155 consistent gets were performed during the hard parse. The first STAT line shows that the SQL statement actually required 355 consistent gets and no physical reads (SQL*Plus showed that 514 consistent gets and 15 physical reads were performed). 355 + 155 = 510, which is just less than the 514 consistent gets reported by SQL*Plus, so we could look further up in the trace file to find the remaining 4 consistent gets.

          Let's take a look at the PARSE_TEST3 trace file:
          ...
          =====================
          PARSING IN CURSOR #3 len=646 dep=1 uid=60 oct=3 lid=60 tim=518053123679 hv=1391468433 ad='2264adec' sqlid='16htvx19g07wj'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')
           NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_00"), NVL(SUM(C2),:"SYS_B_01"), COUNT(DISTINCT C3),
           NVL(SUM(CASE WHEN C3 IS NULL THEN :"SYS_B_02" ELSE :"SYS_B_03" END),:"SYS_B_04") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("T1")
           FULL("T1") NO_PARALLEL_INDEX("T1") */ :"SYS_B_05" AS C1, CASE WHEN "T1"."C1">=:"SYS_B_06" AND "T1"."C1"<=:"SYS_B_07" THEN :"SYS_B_08"
           ELSE :"SYS_B_09" END AS C2, "T1"."C1" AS C3 FROM "T1" SAMPLE BLOCK (:"SYS_B_10" , :"SYS_B_11") SEED (:"SYS_B_12") "T1") SAMPLESUB
          END OF STMT
          PARSE #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3906273573,tim=518053123679
          EXEC #3:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3906273573,tim=518053123679
          FETCH #3:c=15625,e=0,p=0,cr=71,cu=0,mis=0,r=1,dep=1,og=1,plh=3906273573,tim=518053123679
          STAT #3 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT GROUP BY (cr=71 pr=0 pw=0 time=0 us)'
          STAT #3 id=2 cnt=3410 pid=1 pos=1 obj=102003 op='TABLE ACCESS SAMPLE T1 (cr=71 pr=0 pw=0 time=0 us cost=2 size=75 card=3)'
          CLOSE #3:c=0,e=0,dep=1,type=0,tim=518053123679
          =====================
          PARSING IN CURSOR #4 len=471 dep=1 uid=60 oct=3 lid=60 tim=518053123679 hv=1212909034 ad='1f5d5b28' sqlid='c5sn2v544r1ga'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB)
           NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM (SELECT /*+ NO_PARALLEL("T1") INDEX("T1" IND_T1_C1)
           NO_PARALLEL_INDEX("T1") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3  FROM "T1" "T1" WHERE "T1"."C1">=:"SYS_B_6"
           AND "T1"."C1"<=:"SYS_B_7" AND ROWNUM <= :"SYS_B_8") SAMPLESUB
          END OF STMT
          PARSE #4:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=41534134,tim=518053123679
          EXEC #4:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=41534134,tim=518053123679
          FETCH #4:c=0,e=0,p=4,cr=10,cu=0,mis=0,r=1,dep=1,og=1,plh=41534134,tim=518053123679
          STAT #4 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=10 pr=4 pw=0 time=0 us)'
          STAT #4 id=2 cnt=2000 pid=1 pos=1 obj=0 op='VIEW  (cr=10 pr=4 pw=0 time=0 us cost=12 size=390 card=10)'
          STAT #4 id=3 cnt=2000 pid=2 pos=1 obj=0 op='COUNT STOPKEY (cr=10 pr=4 pw=0 time=0 us)'
          STAT #4 id=4 cnt=2000 pid=3 pos=1 obj=0 op='FILTER  (cr=10 pr=4 pw=0 time=0 us)'
          STAT #4 id=5 cnt=2000 pid=4 pos=1 obj=102004 op='INDEX RANGE SCAN IND_T1_C1 (cr=10 pr=4 pw=0 time=0 us cost=12 size=429 card=33)'
          CLOSE #4:c=0,e=0,dep=1,type=0,tim=518053123679
          =====================
          PARSING IN CURSOR #2 len=646 dep=1 uid=60 oct=3 lid=60 tim=518053123679 hv=2627297926 ad='1d2877e4' sqlid='0u23vn6f9ksn6'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')
           NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_00"), NVL(SUM(C2),:"SYS_B_01"), COUNT(DISTINCT C3),
           NVL(SUM(CASE WHEN C3 IS NULL THEN :"SYS_B_02" ELSE :"SYS_B_03" END),:"SYS_B_04") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("T2") FULL("T2")
           NO_PARALLEL_INDEX("T2") */ :"SYS_B_05" AS C1, CASE WHEN "T2"."C1">=:"SYS_B_06" AND "T2"."C1"<=:"SYS_B_07" THEN :"SYS_B_08" ELSE :"SYS_B_09" END AS C2,
           "T2"."C1" AS C3 FROM "T2" SAMPLE BLOCK (:"SYS_B_10" , :"SYS_B_11") SEED (:"SYS_B_12") "T2") SAMPLESUB
          END OF STMT
          PARSE #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=724732973,tim=518053123679
          EXEC #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=724732973,tim=518053123679
          FETCH #2:c=0,e=31256,p=19,cr=71,cu=0,mis=0,r=1,dep=1,og=1,plh=724732973,tim=518053154935
          STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT GROUP BY (cr=71 pr=19 pw=0 time=0 us)'
          STAT #2 id=2 cnt=3420 pid=1 pos=1 obj=102006 op='TABLE ACCESS SAMPLE T2 (cr=71 pr=19 pw=0 time=0 us cost=2 size=75 card=3)'
          CLOSE #2:c=0,e=0,dep=1,type=0,tim=518053154935
          =====================
          PARSING IN CURSOR #6 len=471 dep=1 uid=60 oct=3 lid=60 tim=518053154935 hv=2390595667 ad='1f59c3c4' sqlid='5xf39uf77v62m'
          SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */
           NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM (SELECT /*+ NO_PARALLEL("T2") INDEX("T2" IND_T2_C1)
           NO_PARALLEL_INDEX("T2") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3  FROM "T2" "T2" WHERE "T2"."C1">=:"SYS_B_6" AND "T2"."C1"<=:"SYS_B_7"
           AND ROWNUM <= :"SYS_B_8") SAMPLESUB
          END OF STMT
          PARSE #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=4155399029,tim=518053154935
          EXEC #6:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=4155399029,tim=518053154935
          FETCH #6:c=0,e=31251,p=7,cr=16,cu=0,mis=0,r=1,dep=1,og=1,plh=4155399029,tim=518053186186
          STAT #6 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=16 pr=7 pw=0 time=0 us)'
          STAT #6 id=2 cnt=2000 pid=1 pos=1 obj=0 op='VIEW  (cr=16 pr=7 pw=0 time=0 us cost=12 size=390 card=10)'
          STAT #6 id=3 cnt=2000 pid=2 pos=1 obj=0 op='COUNT STOPKEY (cr=16 pr=7 pw=0 time=0 us)'
          STAT #6 id=4 cnt=2000 pid=3 pos=1 obj=0 op='FILTER  (cr=16 pr=7 pw=0 time=0 us)'
          STAT #6 id=5 cnt=2000 pid=4 pos=1 obj=102007 op='INDEX RANGE SCAN IND_T2_C1 (cr=16 pr=7 pw=0 time=0 us cost=12 size=429 card=33)'
          CLOSE #6:c=0,e=0,dep=1,type=0,tim=518053186186
          =====================
          PARSING IN CURSOR #5 len=179 dep=0 uid=60 oct=3 lid=60 tim=518053186186 hv=3811374996 ad='28520570' sqlid='0m07kq3jktxwn'
          SELECT /* PARSE_TEST3 */
            T1.C1 T1_C1,
            SUBSTR(T1.C3,1,10) T1_C3,
            T2.C2 T2_C2,
            SUBSTR(T2.C3,1,10) T2_C3
          FROM
            T1,
            T2
          WHERE
            T1.C1=T2.C1
            AND T1.C1 BETWEEN 4001 AND 6000
          END OF STMT
          PARSE #5:c=15625,e=62507,p=30,cr=172,cu=0,mis=1,r=0,dep=0,og=1,plh=169351222,tim=518053186186
          EXEC #5:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=169351222,tim=518053186186
          ...
          FETCH #5:c=0,e=0,p=0,cr=2,cu=0,mis=0,r=4,dep=0,og=1,plh=169351222,tim=518053279932
          STAT #5 id=1 cnt=2000 pid=0 pos=1 obj=0 op='HASH JOIN  (cr=396 pr=72 pw=0 time=0 us cost=48 size=284000 card=2000)'
          STAT #5 id=2 cnt=2000 pid=1 pos=1 obj=102003 op='TABLE ACCESS BY INDEX ROWID T1 (cr=44 pr=35 pw=0 time=0 us cost=22 size=130000 card=2000)'
          STAT #5 id=3 cnt=2000 pid=2 pos=1 obj=102004 op='INDEX RANGE SCAN IND_T1_C1 (cr=6 pr=0 pw=0 time=0 us cost=6 size=0 card=2000)'
          STAT #5 id=4 cnt=2000 pid=1 pos=2 obj=102006 op='TABLE ACCESS BY INDEX ROWID T2 (cr=352 pr=37 pw=0 time=0 us cost=25 size=154000 card=2000)'
          STAT #5 id=5 cnt=2000 pid=4 pos=1 obj=102007 op='INDEX RANGE SCAN IND_T2_C1 (cr=143 pr=0 pw=0 time=0 us cost=9 size=0 card=2000)'
          This time you can see that 172 consistent gets were performed during the hard parse. If we add up the consistent gets just before our SQL statement appeared in the trace file (71 + 10 + 71 + 16), we can account for 168 of the 172 consistent gets during the parse of our SQL statement. Note that the SQL_ID for the SQL statement appeared in the trace file ('0m07kq3jktxwn' for the last trace file), so we could do something like this to confirm that dynamic sampling happened during the hard parse:
          SET LINESIZE 140
          SET PAGESIZE 1000
          SET TRIMSPOOL ON
          SET AUTOTRACE OFF
           
          SELECT
            *
          FROM
            TABLE(DBMS_XPLAN.DISPLAY_CURSOR('0m07kq3jktxwn',NULL,'TYPICAL'));
           
          SQL_ID  0m07kq3jktxwn, child number 0
          -------------------------------------
          SELECT /* PARSE_TEST3 */   T1.C1 T1_C1,   SUBSTR(T1.C3,1,10) T1_C3,
          T2.C2 T2_C2,   SUBSTR(T2.C3,1,10) T2_C3 FROM   T1,   T2 WHERE
          T1.C1=T2.C1   AND T1.C1 BETWEEN 4001 AND 6000
           
          Plan hash value: 169351222
           
          ------------------------------------------------------------------------------------------
          | Id  | Operation                    | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
          ------------------------------------------------------------------------------------------
          |   0 | SELECT STATEMENT             |           |       |       |    48 (100)|          |
          |*  1 |  HASH JOIN                   |           |  2000 |   277K|    48   (3)| 00:00:01 |
          |   2 |   TABLE ACCESS BY INDEX ROWID| T1        |  2000 |   126K|    22   (0)| 00:00:01 |
          |*  3 |    INDEX RANGE SCAN          | IND_T1_C1 |  2000 |       |     6   (0)| 00:00:01 |
          |   4 |   TABLE ACCESS BY INDEX ROWID| T2        |  2000 |   150K|    25   (0)| 00:00:01 |
          |*  5 |    INDEX RANGE SCAN          | IND_T2_C1 |  2000 |       |     9   (0)| 00:00:01 |
          ------------------------------------------------------------------------------------------
           
          Predicate Information (identified by operation id):
          ---------------------------------------------------
             1 - access("T1"."C1"="T2"."C1")
             3 - access("T1"."C1">=4001 AND "T1"."C1"<=6000)
             5 - access("T2"."C1">=4001 AND "T2"."C1"<=6000)
           
          Note
          -----
             - dynamic sampling used for this statement
           
          SQL_ID  0m07kq3jktxwn, child number 1
          -------------------------------------
          SELECT /* PARSE_TEST3 */   T1.C1 T1_C1,   SUBSTR(T1.C3,1,10) T1_C3,
          T2.C2 T2_C2,   SUBSTR(T2.C3,1,10) T2_C3 FROM   T1,   T2 WHERE
          T1.C1=T2.C1   AND T1.C1 BETWEEN 4001 AND 6000
           
          Plan hash value: 169351222
           
          ------------------------------------------------------------------------------------------
          | Id  | Operation                    | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
          ------------------------------------------------------------------------------------------
          |   0 | SELECT STATEMENT             |           |       |       |    48 (100)|          |
          |*  1 |  HASH JOIN                   |           |  2000 |   277K|    48   (3)| 00:00:01 |
          |   2 |   TABLE ACCESS BY INDEX ROWID| T1        |  2000 |   126K|    22   (0)| 00:00:01 |
          |*  3 |    INDEX RANGE SCAN          | IND_T1_C1 |  2000 |       |     6   (0)| 00:00:01 |
          |   4 |   TABLE ACCESS BY INDEX ROWID| T2        |  2000 |   150K|    25   (0)| 00:00:01 |
          |*  5 |    INDEX RANGE SCAN          | IND_T2_C1 |  2000 |       |     9   (0)| 00:00:01 |
          ------------------------------------------------------------------------------------------
           
          Predicate Information (identified by operation id):
          ---------------------------------------------------
             1 - access("T1"."C1"="T2"."C1")
             3 - access("T1"."C1">=4001 AND "T1"."C1"<=6000)
             5 - access("T2"."C1">=4001 AND "T2"."C1"<=6000)
           
          Note
          -----
             - dynamic sampling used for this statement
          The note at the bottom of each execution plan shows that dynamic sampling happened during the hard parse. Note also that there are two child cursors with the same execution plan. One was created with a 10046 trace active, and the other was created with a disabled 10046 trace.

          Charles Hooper
          Co-author of "Expert Oracle Practices: Oracle Database Administration from the Oak Table"
          http://hoopercharles.wordpress.com/
          IT Manager/Oracle DBA
          K&M Machine-Fabricating, Inc.
          • 17. Re: high consistent read during parse call | tkprof output
            PAB
            I Want to continue this discussion, because lots of valuable comments/views are coming from experts.
            • 18. Re: high consistent read during parse call | tkprof output
              PAB
              I want to add something here....

              Consistent read during Select is happen when some one Update table. But here in my case no DDL operation is performed by me. And I am sole user of database.

              So, is consistent read is due to some system operation?

              Please give your valuable comments.

              Thanks
              • 19. Re: high consistent read during parse call | tkprof output
                askraks
                deleted

                Edited by: Rakesh jayappa on Oct 7, 2010 9:40 PM
                • 20. Re: high consistent read during parse call | tkprof output
                  askraks
                  there was some in URL - deleted

                  Edited by: Rakesh jayappa on Oct 7, 2010 9:41 PM
                  • 21. Re: high consistent read during parse call | tkprof output
                    askraks
                    Hi,

                    Let me comment what i know

                    Here the problem not with the select statement but the problem with DML happening on the base table like ind$,seg$,obj$.

                    example:

                    1) Lets assume you are executing select statement at 6.40PM.
                    2) There are few update statement already executing ( started at 6.30 pm) on the table and internally it will modify the base tables.( big update statement)
                    3) So you need get CR block of base tables while executing the select statement not new one.

                    That is main reason why the query showing high during the parse phase.

                    test:

                    1)on a test box create a table and collect the stats
                    2) from one session execute the huge update statement it has to take 15 to 20min update.
                    3) now execute the select statment from another session


                    hope this helps you


                    Kind Regards,
                    Rakesh jayappa
                    • 22. Re: high consistent read during parse call | tkprof output
                      Jonathan Lewis
                      PAB wrote:

                      Consistent read during Select is happen when some one Update table. But here in my case no DDL operation is performed by me. And I am sole user of database.

                      So, is consistent read is due to some system operation?
                      Your idea of "consistent read" is wrong (and many people make the same mistake).
                      The easiest way to think of consistent reads is this:
                      <ul>
                      If you're not doing a current read then the only alternative is to do a consistent read.
                      Typically you do current reads because you want to change a block
                      </ul>

                      Regards
                      Jonathan Lewis
                      • 23. Re: high consistent read during parse call | tkprof output
                        askraks
                        ####################################################
                        If you're not doing a current read then the only alternative is to do a consistent read.
                        Typically you do current reads because you want to change a block

                        ################################################

                        So when oracle will modify the block? :)

                        I think that is what i posted, am i correct Jonathan?

                        Kind Regards,
                        Rakesh Jayappa
                        • 24. Re: high consistent read during parse call | tkprof output
                          Jonathan Lewis
                          Rakesh jayappa wrote:

                          I think that is what i posted, am i correct Jonathan?
                          The OP seemed to be asking why he was seeing consistent reads when there was no other activity on the database.
                          You seemed to give an explanation of why you get consistent reads when other sessions are active and interfering with your time-line.

                          My point was that consistent reads are what happen "by default" - even if nothing has been modifying the data for ages.

                          Regards
                          Jonathan Lewis
                          1 2 Previous Next