tuning sql queries....
From: Zabair Ahmed <roon987_at_yahoo.co.uk>
Date: Tue, 6 Sep 2011 13:59:26 +0100 (BST)
Message-ID: <1315313966.76334.YahooMailClassic_at_web25408.mail.ukl.yahoo.com>
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
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
group by length(loc.rowid))
ORDER BY per.last_name
Optimizer mode: ALL_ROWS
Parsing user id: 193 (APPS)
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)
'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
group by length(loc.rowid))
ORDER BY per.last_name
Optimizer mode: ALL_ROWS
Parsing user id: 193 (APPS)
'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
Date: Tue, 6 Sep 2011 13:59:26 +0100 (BST)
Message-ID: <1315313966.76334.YahooMailClassic_at_web25408.mail.ukl.yahoo.com>
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_idgroup 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 0Misses 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 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
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))
'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_idgroup 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 0Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 193 (APPS)
Rows Execution Plan ------- ---------------------------------------------------0 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
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))
'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
-- http://www.freelists.org/webpage/oracle-lReceived on Tue Sep 06 2011 - 07:59:26 CDT