tkprof Analysis

User_URPA8

Hi Experts,

Can someone please help me in understanding the below tkprof.Need some approximate analysis.The same is attached to notepad for better format.

call     count       cpu    elapsed       disk      query    current        rows

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

Parse        2      0.00       0.00          0          0          2           0

Execute 842615     19.53      19.57          0         22          0           0

Fetch   842615  23333.33   23416.81         10 3469943694          0      842615

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

total   1685232  23352.86   23436.39         10 3469943716          2      842615

Misses in library cache during parse: 2

Misses in library cache during execute: 2

Optimizer mode: ALL_ROWS

Parsing user id: 173     (recursive depth: 1)

Number of plan statistics captured: 350

Rows (1st) Rows (avg) Rows (max)  Row Source Operation

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

         1          1          1  SORT AGGREGATE (cr=17522 pr=0 pw=0 time=33379 us)

         0          0          1   VIEW  (cr=17522 pr=0 pw=0 time=33376 us cost=607 size=13 card=1)

         4          4         14    COUNT STOPKEY (cr=17522 pr=0 pw=0 time=33366 us)

         4          4         14     VIEW  (cr=17522 pr=0 pw=0 time=33364 us cost=607 size=13 card=1)

         4          4         14      SORT ORDER BY STOPKEY (cr=17522 pr=0 pw=0 time=33363 us cost=607 size=188 card=1)

       465       1135       1994       FILTER  (cr=17522 pr=0 pw=0 time=38758 us)

       467       1139       1998        NESTED LOOPS ANTI (cr=17508 pr=0 pw=0 time=35080 us cost=597 size=188 card=1)

       468       1139       1998         NESTED LOOPS  (cr=15219 pr=0 pw=0 time=33437 us cost=596 size=178 card=1)

       468       1139       1998          NESTED LOOPS  (cr=15214 pr=0 pw=0 time=31798 us cost=595 size=165 card=1)

       468       1139       1998           NESTED LOOPS  (cr=14071 pr=0 pw=0 time=30329 us cost=594 size=152 card=1)

       468       1139       1998            NESTED LOOPS  (cr=14067 pr=0 pw=0 time=29041 us cost=593 size=139 card=1)

       468       1139       1998             NESTED LOOPS  (cr=12923 pr=0 pw=0 time=27217 us cost=592 size=126 card=1)

       608       1472       2381              NESTED LOOPS  (cr=1639 pr=0 pw=0 time=5551 us cost=450 size=6578 card=143)

         1          1          1               NESTED LOOPS  (cr=4 pr=0 pw=0 time=8 us cost=2 size=19 card=1)

         1          1          1                TABLE ACCESS BY INDEX ROWID XXABC_COLLEGE_MASTER_TBL (cr=2 pr=0 pw=0 time=4 us cost=1 size=6 card=1)

         1          1          1                 INDEX UNIQUE SCAN XXABC_COLLEGES_PK (cr=1 pr=0 pw=0 time=2 us cost=0 size=0 card=1)(object id 2313929)

         1          1          1                TABLE ACCESS BY INDEX ROWID XXABC_LOV_MASTER_TBL (cr=2 pr=0 pw=0 time=3 us cost=1 size=13 card=1)

         1          1          1                 INDEX UNIQUE SCAN XXABC_LOVS_PK (cr=1 pr=0 pw=0 time=2 us cost=0 size=0 card=1)(object id 2313914)

       608       1472       2381               TABLE ACCESS FULL XXABC_APPLICANT_COURSPREFS_TBL (cr=1635 pr=0 pw=0 time=5324 us cost=448 size=3861 card=143)

       468       1139       1998              TABLE ACCESS BY INDEX ROWID XXABC_APPLICANT_DETAILS_TBL (cr=11284 pr=0 pw=0 time=18471 us cost=1 size=80 card=1)

       579       1382       2339               INDEX UNIQUE SCAN XXABC_APPLICANTS_PK (cr=10419 pr=0 pw=0 time=16014 us cost=0 size=0 card=1)(object id 2316264)

         0          1          3                NESTED LOOPS  (cr=4420 pr=0 pw=0 time=3972 us cost=3 size=26 card=1)

         2          2         13                 TABLE ACCESS BY INDEX ROWID XXABC_APPLICANT_COURSPREFS_TBL (cr=4416 pr=0 pw=0 time=3594 us cost=2 size=14 card=1)

       608       1472       2381                  INDEX UNIQUE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=2944 pr=0 pw=0 time=2140 us cost=1 size=0 card=1)(object id 2316268)

         0          1          3                 TABLE ACCESS BY INDEX ROWID XXABC_CATEGORY_MASTER_TBL (cr=3 pr=0 pw=0 time=6 us cost=1 size=12 card=1)

         2          2         13                  INDEX UNIQUE SCAN XXABC_CATEGORY_PK (cr=2 pr=0 pw=0 time=4 us cost=0 size=0 card=1)(object id 2313948)

       608       1472       2381                  INDEX UNIQUE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=2944 pr=0 pw=0 time=2140 us cost=1 size=0 card=1)(object id 2316268)

         0          1          3                 TABLE ACCESS BY INDEX ROWID XXABC_CATEGORY_MASTER_TBL (cr=3 pr=0 pw=0 time=6 us cost=1 size=12 card=1)

         2          2         13                  INDEX UNIQUE SCAN XXABC_CATEGORY_PK (cr=2 pr=0 pw=0 time=4 us cost=0 size=0 card=1)(object id 2313948)

        39        251        576                TABLE ACCESS BY INDEX ROWID BATCHED XXABC_APPLICANT_COURSPREFS_TBL (cr=2371 pr=0 pw=0 time=4787 us cost=3 size=10 card=1)

      4693       8691      13009                 INDEX RANGE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=1502 pr=0 pw=0 time=2613 us cost=2 size=0 card=4)(object id 2316268)

         5          8         33                TABLE ACCESS BY INDEX ROWID BATCHED XXABC_APPLICANT_COURSPREFS_TBL (cr=2255 pr=0 pw=0 time=3760 us cost=3 size=10 card=1)

      4513       8172      12952                 INDEX RANGE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=1418 pr=0 pw=0 time=2105 us cost=2 size=0 card=4)(object id 2316268)

       468       1139       1998             TABLE ACCESS BY INDEX ROWID XXABC_LOV_MASTER_TBL (cr=1143 pr=0 pw=0 time=1318 us cost=1 size=13 card=1)

       468       1139       1998              INDEX UNIQUE SCAN XXABC_LOVS_PK (cr=4 pr=0 pw=0 time=515 us cost=0 size=0 card=1)(object id 2313914)

       468       1139       1998            INDEX UNIQUE SCAN XXABC_LOVS_PK (cr=4 pr=0 pw=0 time=469 us cost=0 size=0 card=1)(object id 2313914)

       468       1139       1998           TABLE ACCESS BY INDEX ROWID XXABC_LOV_MASTER_TBL (cr=1143 pr=0 pw=0 time=1077 us cost=1 size=13 card=1)

       468       1139       1998            INDEX UNIQUE SCAN XXABC_LOVS_PK (cr=4 pr=0 pw=0 time=428 us cost=0 size=0 card=1)(object id 2313914)

       468       1139       1998          TABLE ACCESS BY INDEX ROWID XXABC_LOV_MASTER_TBL (cr=5 pr=0 pw=0 time=1145 us cost=1 size=13 card=1)

       468       1139       1998           INDEX UNIQUE SCAN XXABC_LOVS_PK (cr=4 pr=0 pw=0 time=441 us cost=0 size=0 card=1)(object id 2313914)

         1          0          8         TABLE ACCESS BY INDEX ROWID XXABC_APPLICANT_COURSPREFS_TBL (cr=2289 pr=0 pw=0 time=1530 us cost=1 size=35510 card=3551)

       468       1139       1998          INDEX UNIQUE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=1150 pr=0 pw=0 time=875 us cost=0 size=0 card=1)(object id 2316268)

         0          0          0        VIEW  index$_join$_014 (cr=13 pr=0 pw=0 time=287 us cost=0 size=12 card=1)

         0          0          0         HASH JOIN  (cr=13 pr=0 pw=0 time=285 us)

         6          6          6          INDEX RANGE SCAN XXABC_CATEGORY_PK (cr=6 pr=0 pw=0 time=14 us cost=0 size=12 card=1)(object id 2313948)

        12         11         12          INLIST ITERATOR  (cr=8 pr=0 pw=0 time=23 us)

        12         11         12           INDEX UNIQUE SCAN XXABC_CATEGORY_CODE_UK (cr=8 pr=0 pw=0 time=18 us cost=0 size=12 card=1)(object id 2313946)

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  gc cr grant 2-way                               9        0.00          0.00

  db file sequential read                        10        0.00          0.00

  latch: row cache objects                       10        0.00          0.00

  latch: shared pool                             17        0.00          0.00

  resmgr:cpu quantum                             21        0.00          0.00

********************************************************************************

Thank you,

satish

Jonathan Lewis

3510875 wrote:
I would like to ask one more question.Is this index need to be unique or nonunique?
CREATE INDEX "XXADM"."XXADM_APPLCNT_APPLICANT_STATUS" ON "XXADM"."XXADM_APPLICANT_COURSPREFS_TBL"("APPLICANT_ID","STATUS_FLAG") COMPRESS 1;

There is no way to deduce whether or not the combination of  (application_id, status_flag) should be constrained to be unique across the table. However if that was supposed to be the case there would already be a uniqueness constraint on the table to express that rule, and that would have created the index automatically. So there are no indications that the combination is supposed to be unique, so I wouldn't introduce one now.  Create the index non-unique.

Regards

Jonathan Lewis

SureshMuddaveerappa

Hi Satish,

I fee the question is too generic. It would be easier for the community feedback if you identify the specifics. Check out ID 32951.1, document ID 2556202.1, document ID 211498.1.

Hope this helps

Cheers

Suresh

User_URPA8

Sorry,Missed to add the sql statement.Below is the one.

SELECT COUNT(applicant_id)

         FROM (SELECT applicant_id,

                    academic_year,

                     applicant_gender,

                     medium_of_study,

                     education_type,

                     college_id,

                     course_id,

                     medium_id,

                     hostel_required,

                     preference_order,

                     status_flag,

                     attribute7,  -- Added on 7-mar-20

                     college_status_flag,

                     percentage,

--                     group_percentage,

                     caste_category,

                     alloted_category,

                     NULL allotment_type

                     FROM (

                SELECT adt.applicant_id,

                     lmt_gender.lov_code applicant_gender,

                     adt.medium_of_study,

                     act.college_id,

                     lmt_education_type.lov_code education_type,

                     act.course_id,

                     act.medium_id,

                     act.hostel_required,

                     act.preference_order,

                     act.status_flag,

                     act.attribute7, -- Added on 7-mar-20

                     adt.college_status_flag,

                     adt.academic_year,

                     adt.percentage,

                     adt.applicant_dob,

                     adt.legacy_appln_date,

                     adt.caste_category,

                     act.attribute1 alloted_category,

                     DECODE (lmt_pass.lov_code,  'ATTFIRST', 1,  'COMPARTL', 2,  3)

                        order_of_pass,

                     DECODE (late_entry_flag,  'N', 1,  'Y', 2,  3)      order_of_entry,

                     DECODE (lmt_appearance.lov_code,  'REGULAR', 1,  'PRIVATE', 2,  3)

                        order_of_appearance,

                     DECODE (adt.is_ttd_employ_ward,  'Y', 1,  'N', 2,  3) order_of_ttd_emp,

                     DECODE (adt.is_balbhavan_studnt,  'Y', 1,  'N', 2,  3)

                        order_of_schooling

                        ,act.attribute3 course_qe_priority

                        ,adt.is_local_canditature_valid

                        ,adt.is_ttd_emp_ward_info_valid

                        ,adt.is_sv_bm_student_info_valid

                        ,adt.is_social_ctgry_info_valid

--                        ,DECODE(adt.college_status_flag,'B',1,'O',2,'N',3) order_of_status

--                        ,(SELECT ROUND(((SUM(aqt.MARKS_OBTAINED)/sum(total_marks))*100),2)

--                                FROM xxadm.xxadm_applcnt_qlfyxmmarks_tbl aqt,

--                                 xxadm.xxadm_subject_master_tbl    smt

--                           WHERE aqt.prereq_subject_id = smt.subject_id

--                                 AND aqt.applicant_id = adt.applicant_id

--                                 AND smt.subject_code IN ('MATHS','GS','SS')) group_percentage

                FROM xxadm.xxadm_applicant_details_tbl  adt,

                     xxadm.xxadm_applicant_coursprefs_tbl act,

                     xxadm.xxadm_college_master_tbl     cmt,

                     xxadm.xxadm_course_master_tbl      crmt,

                     xxadm.xxadm_medium_master_tbl      mmt,

                     xxadm.xxadm_lov_master_tbl         lmt_gender,

                     xxadm.xxadm_lov_master_tbl         lmt_pass,

                     xxadm.xxadm_lov_master_tbl         lmt_appearance,

                     xxadm.xxadm_lov_master_tbl         lmt_religion,

                     xxadm.xxadm_lov_master_tbl         lmt_education_type

                WHERE    adt.applicant_id = act.applicant_id

                     AND act.college_id = cmt.college_id

                     AND act.course_id = crmt.course_id

                     AND act.medium_id = mmt.medium_id

                     AND adt.applicant_gender = lmt_gender.lov_id

                     AND adt.pass_type = lmt_pass.lov_id

                     AND adt.appearance_type = lmt_appearance.lov_id

                     AND adt.religion = lmt_religion.lov_id

                     AND cmt.education_type = lmt_education_type.lov_id

                     AND adt.status = 'Active'

                     AND 1= (CASE WHEN act.hostel_required='Y'

                                THEN (CASE WHEN adt.distance_in_kms >20

                            AND  lmt_religion.lov_code = 'HINDU'

                            AND adt.caste_category NOT IN

                            (SELECT category_id

                               FROM xxadm.xxadm_category_master_tbl

                              WHERE category_code IN ('BACKWRDC', 'BACKWRDE'))

                              THEN 1

                              ELSE 2 END)

                              ELSE

                              1 END)

                    AND 1= (CASE WHEN act.hostel_required ='Y'

                            THEN (CASE WHEN (lmt_education_type.lov_code='COEDUCOL' AND lmt_gender.lov_code='FEMALE')

                            THEN

                            2

                            ELSE

                            1 END )

                            ELSE

                            1 END)  AND adt.course_applied_for = 'DEG' AND ( adt.college_status_flag IS NULL OR adt.college_status_flag IN ('N','T','C','B','O')) AND act.preference_order<=NVL((SELECT  preference_order FROM xxadm.xxadm_applicant_coursprefs_tbl act1 WHERE act1.applicant_id=adt.applicant_id

                                                       AND status_flag IN('B','T','C','O')),act.preference_order) AND act.preference_order>=NVL((SELECT  preference_order

                                                       FROM xxadm.xxadm_applicant_coursprefs_tbl act2 WHERE act2.applicant_id=adt.applicant_id

                                                       AND status_flag ='C'),act.preference_order)

                                                        AND act.preference_order NOT IN (SELECT act3.preference_order FROM xxadm.xxadm_applicant_coursprefs_tbl act3

                                                            WHERE act3.applicant_id = adt.applicant_id AND act3.status_flag ='O') AND act.preference_order NOT IN (SELECT act1.preference_order FROM xxadm.xxadm_applicant_coursprefs_tbl act1 WHERE act1.applicant_id = adt.applicant_id AND act1.status_flag IN ('C','B')

                                                         AND act1.attribute1 IN (SELECT category_id FROM xxadm.xxadm_category_master_tbl WHERE category_code IN ('OPENMERT')) AND NVL(act1.attribute7,'N')='N') AND cmt.college_id = :p_college_id

                                                     AND crmt.course_id = :p_course_id

                                                     AND mmt.medium_id  = :p_medium_id

                                                     AND act.hostel_required = :p_hostel_required

                                    ORDER BY

--                                    order_of_entry,

                                    -- order_of_appearance,

--                                    order_of_status,

                                     order_of_pass,

                                     course_qe_priority,

                                     percentage DESC,

--                                     group_percentage DESC,

                                     applicant_dob,

                                     legacy_appln_date) WHERE ROWNUM<=:p_seats) WHERE applicant_id=:p_applicant_id;

User_URPA8

This sql has complex login and so seeking your help.Please suggest

User_URPA8

Hi Experts,

Upto my understanding,the major elapsed time is taken by fetch operation.

Every fetch is visiting 4118 blocks to retrieve just 1 row(3469943694/842615).I need to understand which part of rowsource plan do i focus to reduce the blocks visited.

Many thanks

BPeaslandDBA

Total cost of the SQL statement is 607. But this step:

TABLE ACCESS FULL XXABC_APPLICANT_COURSPREFS_TBL (cr=1635 pr=0 pw=0 time=5324 us cost=448 size=3861

that one contributes 448 to the overall cost. So I think this full table scan is causing the most performance pain. Make sure you have the appropriate indexes to help with the join to this table.

Cheers,

Brian

User_URPA8

This table already having a index

SQL> select INDEX_NAME,COLUMN_NAME,COLUMN_POSITION from dba_ind_columns where table_name='XXABC_APPLICANT_COURSPREFS_TBL' and table_owner='XXABC';

INDEX_NAME                    |COLUMN_NAME                             |COLUMN_POSITION

------------------------------|----------------------------------------|---------------

XXABC_APPLCNT_PREFS_UK        |APPLICANT_ID                            |              1

XXABC_APPLCNT_PREFS_UK        |COLLEGE_ID                              |              2

XXABC_APPLCNT_PREFS_UK        |COURSE_ID                               |              3

XXABC_APPLCNT_PREFS_UK        |MEDIUM_ID                               |              4

XXABC_APPLCNT_PREFS_UK        |HOSTEL_REQUIRED                         |              5

XXABC_APPLCNT_PREF_ORDER_UK   |APPLICANT_ID                            |              1

XXABC_APPLCNT_PREF_ORDER_UK   |PREFERENCE_ORDER                        |              2

7 rows selected.

SQL> select count(*) from XXABC.XXABC_APPLICANT_COURSPREFS_TBL;

  COUNT(*)

----------

    117302

JohnWatson2

Can you try

ALTER SESSION SET OPTIMIZER DYNAMIC SAMPLING=4;

and see what tkprof says then? I think that the optimizer is underestimating the number of rows coming out of some tables and therefore using indexes and loops when scans and hash joins might be better.

Jonathan Lewis

The most significant feature of this output is that the query was executed 842,615 times.

The average execution time isn't a total disaster - though the plan shows some obvious inefficiencies - so the first strategy is probably is ASK if it would be feasible to find a way of executing the query much less frequently.

When trying to optimize, remember that the rowsource execution stats you get with the plan are just for the first execution that was dumped so (though the plan will stay the same) the execution work may vary significantly between executions.

The most resource intensive part of the query is the following:

TABLE ACCESS BY INDEX ROWID XXABC_APPLICANT_DETAILS_TBL (cr=11284 pr=0 pw=0 time=18471 us cost=1 size=80 card=1)

INDEX UNIQUE SCAN XXABC_APPLICANTS_PK (cr=10419 pr=0 pw=0 time=16014 us cost=0 size=0 card=1)(object id 2316264)

  NESTED LOOPS  (cr=4420 pr=0 pw=0 time=3972 us cost=3 size=26 card=1)

   TABLE ACCESS BY INDEX ROWID XXABC_APPLICANT_COURSPREFS_TBL (cr=4416 pr=0 pw=0 time=3594 us cost=2 size=14 card=1)

    INDEX UNIQUE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=2944 pr=0 pw=0 time=2140 us cost=1 size=0 card=1)(object id 2316268)

   TABLE ACCESS BY INDEX ROWID XXABC_CATEGORY_MASTER_TBL (cr=3 pr=0 pw=0 time=6 us cost=1 size=12 card=1)

    INDEX UNIQUE SCAN XXABC_CATEGORY_PK (cr=2 pr=0 pw=0 time=4 us cost=0 size=0 card=1)(object id 2313948)

    INDEX UNIQUE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=2944 pr=0 pw=0 time=2140 us cost=1 size=0 card=1)(object id 2316268)

   TABLE ACCESS BY INDEX ROWID XXABC_CATEGORY_MASTER_TBL (cr=3 pr=0 pw=0 time=6 us cost=1 size=12 card=1)

    INDEX UNIQUE SCAN XXABC_CATEGORY_PK (cr=2 pr=0 pw=0 time=4 us cost=0 size=0 card=1)(object id 2313948)

  TABLE ACCESS BY INDEX ROWID BATCHED XXABC_APPLICANT_COURSPREFS_TBL (cr=2371 pr=0 pw=0 time=4787 us cost=3 size=10 card=1)

   INDEX RANGE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=1502 pr=0 pw=0 time=2613 us cost=2 size=0 card=4)(object id 2316268)

  TABLE ACCESS BY INDEX ROWID BATCHED XXABC_APPLICANT_COURSPREFS_TBL (cr=2255 pr=0 pw=0 time=3760 us cost=3 size=10 card=1)

   INDEX RANGE SCAN XXABC_APPLCNT_PREF_ORDER_UK (cr=1418 pr=0 pw=0 time=2105 us cost=2 size=0 card=4)(object id 2316268)

The "table access full" that precedes it is a red herring - ultimately this part of the query operates (a minimum of) 608 times reducing the 608 rows to 468 rows, and ultimately you get down to 465 rows, so there's no rearrangement of the basic join order that will reduce the data much faster before you run this messy bit.  (Similarly the average and max show roughly 20% reduction due to this bit).

The plan corresponds to the string of NOT IN subqueries at the end of your query, and every single bit of the extract shows that Oracle is behaving very efficiently - the problem is the number of times all those NOT INs have to execute for each execution of the main query.

I've highlight a few numbers - the bold AND italic are the direct contributors of CR blocks to the 10,419 I've highlighted the same way in the "index unique scan".  The bold but not italic are indirect contributors (the 2944 comes from a filter subquery to a subquery against an index access which is why it manages to appear twice and has an odd indent on the second occurrence)

You need to find a better way of expressing the messy condition - or need to precreate a single table that can be reference  very efficiently just once to do all the tests.

Note, by the way that part of the "thousands of buffer gets to produce one row" is that you are first getting lots of rows then ordering them, then applying a ROWNUM < :N predicate which discards most of the rows you've found. Comparing the work down with the number of rows of ouput is not necessarily a meandingful test.

Regards

Jonathan Lewis

Jonathan Lewis

I should have suggested you produce an execution plan that includes the predicate section so that we can get a better view of what Oracle has done to transform your query before optimising it. You have an SQL_ID in the tkprof output - try a call (with suitable SQL*Plus formatting) to:

select * from table(dbms_xplan.display_cursor('{your sql id}'));

and post the results here.

Regards

Jonathan Lewis

User_URPA8

My sincere thanks for helping me.

My bad,the plan is no longer in cursor.

SQL> select * from table(dbms_xplan.display_cursor('1n5q5gp58qzc9'));

PLAN_TABLE_OUTPUT

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

SQL_ID: 1n5q5gp58qzc9, child number: 0 cannot be found

I think from AWR,we cannot get the predicate information.Anyways,team will run again within next 3 days and i will share it here.

Between,we have an index on the table XXABC_APPLICANT_COURSPREFS_TBL(as updated in previous updates), but it is not used and gone for full table scan.One more thing,Generally a unique scan should return a single row but the below operation is returning more than 1 row.Is this normal?

Rows (1st) Rows (avg) Rows (max)  Row Source Operation

579       1382       2339               INDEX UNIQUE SCAN XXADM_APPLICANTS_PK (cr=10419 pr=0 pw=0 time=16014 us cost=0 size=0 card=1)(object id 2316264)

Thank you