Re: tuning sql queries....

  • From: Jeremy Schneider <jeremy.schneider@xxxxxxxxxxxxxx>
  • To: roon987@xxxxxxxxxxx
  • Date: Tue, 06 Sep 2011 08:19:36 -0500

If you're comparing two environments where the same SQL statement runs
differently, then the very first thing I'd look at is whether the SQL
statements are using the same plan. The other first thing you need to
check is what the differences are between the two environments... both
in terms of hardware/software environment and data (as Chris has pointed
out).

-J

On 9/6/2011 7:59 AM, Zabair Ahmed wrote:
> I've just been given some trace files, to examine as to why a piece of sql is 
> taking a long time to run in one evironment and not taking so much time in 
> another environment.
>  
> Both the databases are running 11.2.0.1 on AIX 6.1 - am also told that the 
> databases are running on the same SAN.
>  
>  
> First piece of SQL......
>  
>  
>  
> TKPROF: Release 11.2.0.1.0 - Development on Thu Sep 1 20:09:55 2011
> Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.
> Trace file: IHR45R_ora_25035006_APPS.trc
> Sort options: prsela  exeela  fchela  
> ********************************************************************************
> count    = number of times OCI procedure was executed
> cpu      = cpu time in seconds executing 
> elapsed  = elapsed time in seconds executing
> disk     = number of physical reads of buffers from disk
> query    = number of buffers gotten for consistent read
> current  = number of buffers gotten in current mode (usually for update)
> rows     = number of rows processed by the fetch or execute call
> ********************************************************************************
> select per.EMPLOYEE_NUMBER,
>            hou.NAME ORG_NAME,
>            rpaa.assignment_action_id run_assignment_action_id,
>            per.FULL_NAME 
> from hr_organization_units hou,
>        per_all_assignments_f asf,
>          per_people_f per,
>          pay_assignment_actions paa,
>          pay_payroll_actions ppa  ,    
>          pay_assignment_actions rpaa,
>          pay_action_interlocks il,
>          per_time_periods    ptp,
>          pay_payroll_actions rppa    
> where rppa.PAYROLL_ID=:P_PAYROLL_ID 
> AND   rppa.time_period_id=:P_TIME_PERIOD_ID 
> AND   asf.ORGANIZATION_ID = hou.ORGANIZATION_ID
> and    paa.payroll_action_id = ppa.payroll_action_id
> and     ppa.action_type in ('U','P')
> and     ppa.action_status = 'C'
> and     ppa.payroll_id = rppa.payroll_id
> and     ppa.effective_date >= rppa.effective_date
> and     rpaa.assignment_id = paa.assignment_id
> and    per.person_id  = asf.person_id
> and    paa.assignment_id = asf.assignment_id
> and    rppa.date_earned between
>              asf.effective_start_date and asf.effective_end_date
> and    ptp.time_period_id = rppa.time_period_id
> and    rppa.date_earned between
>                  per.effective_start_date and per.effective_end_date
> and    rppa.payroll_action_id = rpaa.payroll_action_id
> and    rpaa.assignment_action_id = il.locked_action_id
> and    paa.assignment_action_id = il.locking_action_id
> and il.rowid        (select
>             substr(max(lpad(aa.action_sequence,15,0)||loc.rowid),
>                    -length(loc.rowid)) latest_act
>         from   pay_assignment_actions aa,
>                pay_action_interlocks loc
>         where loc.locked_action_id = aa.assignment_action_id
>         and   loc.locking_action_id = paa.assignment_action_id
>         group by length(loc.rowid))
> ORDER BY per.last_name
> call     count       cpu    elapsed       disk      query    current        
> rows
> ------- ------  -------- ---------- ---------- ---------- ----------  
> ----------
> Parse        1      0.00       0.00          0          0          0          
>  0
> Execute      1      0.00       0.00          0          0          0          
>  0
> Fetch        1    809.49    1632.05      84914  263024953          0          
>  0
> ------- ------  -------- ---------- ---------- ---------- ----------  
> ----------
> total        3    809.49    1632.05      84914  263024953          0          
>  0
> Misses in library cache during parse: 0
> Optimizer mode: ALL_ROWS
> Parsing user id: 193  (APPS)
> Rows     Row Source Operation
> -------  ---------------------------------------------------
>       0  SORT ORDER BY (cr&3024953 pr„914 pw=0 time=0 us cost590 size&2 
> card=1)
>       0   NESTED LOOPS  (cr&3024953 pr„914 pw=0 time=0 us)
>       0    NESTED LOOPS  (cr&3024953 pr„914 pw=0 time=0 us cost582 size&2 
> card=1)
>       0     NESTED LOOPS  (cr&3024953 pr„914 pw=0 time=0 us cost577 size9 
> card=1)
> 16970762      NESTED LOOPS  (cr"0440177 pr„900 pw=0 time30098816 us cost576 
> size0 card=1)
> 16970762       NESTED LOOPS  (cr9369827 pr„900 pw=0 time73923328 us 
> cost543 sizes272 cardQ6)
> 16970762        HASH JOIN  (cr5526 prG472 pw=0 timeƒ105720 us cost032 
> sizee408 cardQ1)
>   10831         TABLE ACCESS FULL HR_ALL_ORGANIZATION_UNITS_TL (cr2 pr=0 
> pw=0 timeS640 us costG sizeH60 card8)
> 16970762         HASH JOIN  (cr5394 prG472 pw=0 timeG942036 us cost™84 
> size!18824 card%528)
>   10831          TABLE ACCESS FULL HR_ALL_ORGANIZATION_UNITS (cr'7 pr=0 pw=0 
> time89370 us cost† sizeC328 cardT16)
> 16970762          HASH JOIN  (cr5117 prG472 pw=0 time311112 us cost˜97 
> size'00000 card6000)
> 1182286           NESTED LOOPS  (crp268 pr626 pw=0 time`283736 us)
> 1182286            NESTED LOOPS  (cr405 pr061 pw=0 timeh51288 us cost03 
> size&2020 cardY55)
>     119             NESTED LOOPS  (cr3 pr pw=0 time16 us cost sizeg6 
> card&)
>       1              INDEX UNIQUE SCAN PER_TIME_PERIODS_PK (cr=2 pr=0 pw=0 
> time=0 us cost=1 size=4 card=1)(object id 42704)
>     119              INLIST ITERATOR  (cr1 pr pw=0 time80 us)
>     119               TABLE ACCESS BY INDEX ROWID PAY_PAYROLL_ACTIONS (cr1 
> pr pw=0 time62 us cost sizeW2 card&)
>     119                INDEX RANGE SCAN PAY_PAYROLL_ACTIONS_N51 (cr=7 pr=2 
> pw=0 time#6 us cost=3 size=0 cardw)(object id 41293)
> 1182286             INDEX RANGE SCAN PAY_ASSIGNMENT_ACTIONS_N50 (cr282 pr046 
> pw=0 timed07830 us cost=2 size=0 card#1)(object id 40857)
> 1182286            TABLE ACCESS BY INDEX ROWID PAY_ASSIGNMENT_ACTIONS (crf863 
> pr•65 pw=0 time=0 us cost$ sizeA58 card#1)
> 1160908           TABLE ACCESS FULL PER_ALL_ASSIGNMENTS_F (cr4849 pr4846 pw=0 
> time"56153 us cost•82 size5881818 card57478)
> 16970762        TABLE ACCESS BY USER ROWID PAY_ACTION_INTERLOCKS (cr9264301 
> pr7428 pw=0 time=0 us cost=1 size card=1)
> 16964706         SORT GROUP BY (cr2293910 pr1545 pw=0 time=0 us cost=7 sizeV 
> card=2)
> 32113805          NESTED LOOPS  (cr2293910 pr1545 pw=0 time(0380896 us)
> 32113805           NESTED LOOPS  (cr0180105 pr259 pw=0 time3230016 us 
> cost=6 sizeV card=2)
> 32113805            INDEX RANGE SCAN PAY_ACTION_INTERLOCKS_PK (crU952660 
> pre36 pw=0 time2551526 us cost=3 size( card=2)(object id 40837)
> 32113805            INDEX UNIQUE SCAN PAY_ASSIGNMENT_ACTIONS_PK (crd227445 
> prG23 pw=0 time=0 us cost=1 size=0 card=1)(object id 40859)
> 32113805           TABLE ACCESS BY INDEX ROWID PAY_ASSIGNMENT_ACTIONS 
> (cr2113805 pr 286 pw=0 time=0 us cost=2 size card=1)
> 16970762       TABLE ACCESS BY INDEX ROWID PAY_ASSIGNMENT_ACTIONS (crQ070350 
> pr=0 pw=0 time=0 us cost=2 size card=1)
> 16970762        INDEX UNIQUE SCAN PAY_ASSIGNMENT_ACTIONS_PK (cr4099588 pr=0 
> pw=0 time=0 us cost=1 size=0 card=1)(object id 40859)
>       0      TABLE ACCESS BY INDEX ROWID PAY_PAYROLL_ACTIONS (crB584776 pr 
> pw=0 time=0 us cost=1 size) card=1)
> 16970762       INDEX UNIQUE SCAN PAY_PAYROLL_ACTIONS_PK (cr&761707 pr=0 pw=0 
> time=0 us cost=0 size=0 card=1)(object id 41295)
>       0     INDEX RANGE SCAN PER_PEOPLE_F_PK (cr=0 pr=0 pw=0 time=0 us cost=2 
> size=0 card=3)(object id 41790)
>       0    TABLE ACCESS BY INDEX ROWID PER_ALL_PEOPLE_F (cr=0 pr=0 pw=0 
> time=0 us cost=5 sizes card=1)
>
> Rows     Execution Plan
> -------  ---------------------------------------------------
>       0  SELECT STATEMENT   MODE: ALL_ROWS
>       0   SORT (ORDER BY)
>       0    NESTED LOOPS
>       0     NESTED LOOPS
>       0      NESTED LOOPS
> 16970762       NESTED LOOPS
> 16970762        NESTED LOOPS
> 16970762         HASH JOIN
>   10831          TABLE ACCESS   MODE: ANALYZED (FULL) OF 
>                      'HR_ALL_ORGANIZATION_UNITS_TL' (TABLE)
> 16970762          HASH JOIN
>   10831           TABLE ACCESS   MODE: ANALYZED (FULL) OF 
>                       'HR_ALL_ORGANIZATION_UNITS' (TABLE)
> 16970762           HASH JOIN
> 1182286            NESTED LOOPS
> 1182286             NESTED LOOPS
>     119              NESTED LOOPS
>       1               INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                           'PER_TIME_PERIODS_PK' (INDEX (UNIQUE))
>     119               INLIST ITERATOR
>     119                TABLE ACCESS   MODE: ANALYZED (BY 
>                            INDEX ROWID) OF 'PAY_PAYROLL_ACTIONS' (TABLE)
>     119                 INDEX   MODE: ANALYZED (RANGE SCAN) 
>                             OF 'PAY_PAYROLL_ACTIONS_N51' (INDEX)
> 1182286              INDEX   MODE: ANALYZED (RANGE SCAN) OF 
>                          'PAY_ASSIGNMENT_ACTIONS_N50' (INDEX)
> 1182286             TABLE ACCESS   MODE: ANALYZED (BY INDEX 
>                         ROWID) OF 'PAY_ASSIGNMENT_ACTIONS' (TABLE)
> 1160908            TABLE ACCESS   MODE: ANALYZED (FULL) OF 
>                        'PER_ALL_ASSIGNMENTS_F' (TABLE)
> 16970762         TABLE ACCESS   MODE: ANALYZED (BY USER ROWID) OF 
>                     'PAY_ACTION_INTERLOCKS' (TABLE)
> 16964706          SORT (GROUP BY)
> 32113805           NESTED LOOPS
> 32113805            NESTED LOOPS
> 32113805             INDEX   MODE: ANALYZED (RANGE SCAN) OF 
>                         'PAY_ACTION_INTERLOCKS_PK' (INDEX (UNIQUE))
> 32113805             INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                         'PAY_ASSIGNMENT_ACTIONS_PK' (INDEX (UNIQUE))
> 32113805            TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) 
>                        OF 'PAY_ASSIGNMENT_ACTIONS' (TABLE)
> 16970762        TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 
>                    'PAY_ASSIGNMENT_ACTIONS' (TABLE)
> 16970762         INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                     'PAY_ASSIGNMENT_ACTIONS_PK' (INDEX (UNIQUE))
>       0       TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 
>                   'PAY_PAYROLL_ACTIONS' (TABLE)
> 16970762        INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                    'PAY_PAYROLL_ACTIONS_PK' (INDEX (UNIQUE))
>       0      INDEX   MODE: ANALYZED (RANGE SCAN) OF 'PER_PEOPLE_F_PK' 
>                  (INDEX (UNIQUE))
>       0     TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 
>                 'PER_ALL_PEOPLE_F' (TABLE)
>
> Elapsed times include waiting on following events:
>   Event waited on                             Times   Max. Wait  Total Waited
>   ----------------------------------------   Waited  ----------  ------------
>   SQL*Net message to client                       1        0.00          0.00
>   Disk file operations I/O                       16        0.00          0.00
>   db file sequential read                     50068        0.52        284.33
>   asynch descriptor resize                        6        0.00          0.00
>   direct path read                              195        0.04          1.40
>   SQL*Net message from client                     1        0.00          0.00
> ********************************************************************************
>  
>  
>  
> Second piece of SQL.....
>  
>  
>  
>  
> select per.EMPLOYEE_NUMBER,
>            hou.NAME ORG_NAME,
>            rpaa.assignment_action_id run_assignment_action_id,
>            per.FULL_NAME 
> from hr_organization_units hou,
>        per_all_assignments_f asf,
>          per_people_f per,
>          pay_assignment_actions paa,
>          pay_payroll_actions ppa  ,    
>          pay_assignment_actions rpaa,
>          pay_action_interlocks il,
>          per_time_periods    ptp,
>          pay_payroll_actions rppa    
> where rppa.PAYROLL_ID=:P_PAYROLL_ID 
> AND   rppa.time_period_id=:P_TIME_PERIOD_ID 
> AND   asf.ORGANIZATION_ID = hou.ORGANIZATION_ID
> and    paa.payroll_action_id = ppa.payroll_action_id
> and     ppa.action_type in ('U','P')
> and     ppa.action_status = 'C'
> and     ppa.payroll_id = rppa.payroll_id
> and     ppa.effective_date >= rppa.effective_date
> and     rpaa.assignment_id = paa.assignment_id
> and    per.person_id  = asf.person_id
> and    paa.assignment_id = asf.assignment_id
> and    rppa.date_earned between
>              asf.effective_start_date and asf.effective_end_date
> and    ptp.time_period_id = rppa.time_period_id
> and    rppa.date_earned between
>                  per.effective_start_date and per.effective_end_date
> and    rppa.payroll_action_id = rpaa.payroll_action_id
> and    rpaa.assignment_action_id = il.locked_action_id
> and    paa.assignment_action_id = il.locking_action_id
> and il.rowid        (select
>             substr(max(lpad(aa.action_sequence,15,0)||loc.rowid),
>                    -length(loc.rowid)) latest_act
>         from   pay_assignment_actions aa,
>                pay_action_interlocks loc
>         where loc.locked_action_id = aa.assignment_action_id
>         and   loc.locking_action_id = paa.assignment_action_id
>         group by length(loc.rowid))
> ORDER BY per.last_name
> call     count       cpu    elapsed       disk      query    current        
> rows
> ------- ------  -------- ---------- ---------- ---------- ----------  
> ----------
> Parse        1      0.00       0.00          0          0          0          
>  0
> Execute      1      0.00       0.00          0          0          0          
>  0
> Fetch        0      0.00       0.00          0          0          0          
>  0
> ------- ------  -------- ---------- ---------- ---------- ----------  
> ----------
> total        2      0.00       0.00          0          0          0          
>  0
> Misses in library cache during parse: 0
> Optimizer mode: ALL_ROWS
> Parsing user id: 193  (APPS)
> Rows     Execution Plan
> -------  ---------------------------------------------------
>       0  SELECT STATEMENT   MODE: ALL_ROWS
>       0   SORT (ORDER BY)
>       0    NESTED LOOPS
>       0     NESTED LOOPS
>       0      NESTED LOOPS
>       0       NESTED LOOPS
>       0        NESTED LOOPS
>       0         HASH JOIN
>       0          TABLE ACCESS   MODE: ANALYZED (FULL) OF 
>                      'HR_ALL_ORGANIZATION_UNITS_TL' (TABLE)
>       0          HASH JOIN
>       0           TABLE ACCESS   MODE: ANALYZED (FULL) OF 
>                       'HR_ALL_ORGANIZATION_UNITS' (TABLE)
>       0           HASH JOIN
>       0            NESTED LOOPS
>       0             NESTED LOOPS
>       0              NESTED LOOPS
>       0               INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                           'PER_TIME_PERIODS_PK' (INDEX (UNIQUE))
>       0               INLIST ITERATOR
>       0                TABLE ACCESS   MODE: ANALYZED (BY 
>                            INDEX ROWID) OF 'PAY_PAYROLL_ACTIONS' (TABLE)
>       0                 INDEX   MODE: ANALYZED (RANGE SCAN) 
>                             OF 'PAY_PAYROLL_ACTIONS_N51' (INDEX)
>       0              INDEX   MODE: ANALYZED (RANGE SCAN) OF 
>                          'PAY_ASSIGNMENT_ACTIONS_N50' (INDEX)
>       0             TABLE ACCESS   MODE: ANALYZED (BY INDEX 
>                         ROWID) OF 'PAY_ASSIGNMENT_ACTIONS' (TABLE)
>       0            TABLE ACCESS   MODE: ANALYZED (FULL) OF 
>                        'PER_ALL_ASSIGNMENTS_F' (TABLE)
>       0         TABLE ACCESS   MODE: ANALYZED (BY USER ROWID) OF 
>                     'PAY_ACTION_INTERLOCKS' (TABLE)
>       0          SORT (GROUP BY)
>       0           NESTED LOOPS
>       0            NESTED LOOPS
>       0             INDEX   MODE: ANALYZED (RANGE SCAN) OF 
>                         'PAY_ACTION_INTERLOCKS_PK' (INDEX (UNIQUE))
>       0             INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                         'PAY_ASSIGNMENT_ACTIONS_PK' (INDEX (UNIQUE))
>       0            TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) 
>                        OF 'PAY_ASSIGNMENT_ACTIONS' (TABLE)
>       0        TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 
>                    'PAY_ASSIGNMENT_ACTIONS' (TABLE)
>       0         INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                     'PAY_ASSIGNMENT_ACTIONS_PK' (INDEX (UNIQUE))
>       0       TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 
>                   'PAY_PAYROLL_ACTIONS' (TABLE)
>       0        INDEX   MODE: ANALYZED (UNIQUE SCAN) OF 
>                    'PAY_PAYROLL_ACTIONS_PK' (INDEX (UNIQUE))
>       0      INDEX   MODE: ANALYZED (RANGE SCAN) OF 'PER_PEOPLE_F_PK' 
>                  (INDEX (UNIQUE))
>       0     TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 
>                 'PER_ALL_PEOPLE_F' (TABLE)
>
> Elapsed times include waiting on following events:
>   Event waited on                             Times   Max. Wait  Total Waited
>   ----------------------------------------   Waited  ----------  ------------
>   SQL*Net message to client                       1        0.00          0.00
>   Disk file operations I/O                        9        0.00          0.00
>   db file sequential read                   4518987        0.74      10002.88
>   db file scattered read                         59        0.05          0.87
>   asynch descriptor resize                        6        0.00          0.00
>   direct path read                               75        0.03          0.58
>   latch: cache buffers chains                    14        0.00          0.00
>   latch: object queue header operation            1        0.00          0.00
> ********************************************************************************
>  
>  
> Any pointers/guidance as to what is going on here , how to diagnose the 
> problem, what I should be looking etc will be much appreciated.
>  
> Thanks
>  
>  
> --
> //www.freelists.org/webpage/oracle-l
>
>
>


-- 
http://www.ardentperf.com
+1 312-725-9249

Jeremy Schneider
Chicago

--
//www.freelists.org/webpage/oracle-l


Other related posts: