[Oracle-l] tuning sql queries....

[Oracle-l] tuning sql queries....

	Zabair Ahmed
	Sep 6, 2011 at 12:59 pm

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

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

Search Discussions

8 responses
Oldest
Nested

Taylor, Chris David

at Sep 6, 2011 at 1:08 pm

⇧

What are the environments like?

Meaning: Is one production and another test? Which environment is experiencing the problem? How are the systems different (at a high level)?

It may be that you just need to use dbms_stats to gather statistics on the tables & indexes used by the optimizer in the environment that is experiencing the slow performance.

Chris Taylor
Sr. Oracle DBA
Ingram Barge Company
Nashville, TN 37205
Office: 615-517-3355
Cell: 615-663-1673
Email: chris.taylor_at_ingrambarge.com

CONFIDENTIALITY NOTICE: This e-mail and any attachments are confidential and may also be privileged. If you are not the named recipient, please notify the sender immediately and delete the contents of this message without disclosing the contents to anyone, using them for any purpose, or storing or copying the information on any medium.

-----Original Message-----
From: oracle-l-bounce_at_freelists.org On Behalf Of Zabair Ahmed
Sent: Tuesday, September 06, 2011 7:59 AM
To: [email protected]
Subject: tuning sql queries....

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

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

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

reply | permalink

Jeremy Schneider

at Sep 6, 2011 at 1:19 pm

⇧

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

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

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

Jeremy Schneider
Chicago

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

reply | permalink

Jeremy Schneider

at Sep 6, 2011 at 1:26 pm

⇧

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

Jeremy Schneider
Chicago

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

reply | permalink

Wolfgang Breitling

at Sep 6, 2011 at 2:27 pm

⇧

In your "Second piece of SQL�.." trace there is no execution plan ("Row Source Operation") only the explain plan. Why? Is the trace complete? Did it get cut short due to max_dump_file_size limit?

Regards
Wolfgang Breitling
Centrex Consulting Corporation
http://www.centrexcc.com

On 2011-09-06, at 6: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.

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

reply | permalink

Bajwa, Sandeep

at Sep 6, 2011 at 2:29 pm

⇧

Check your Indexes whether they have STATistics or not! They might need rebuild. All of your time is being spent on indexes and nested loops.

gather the statistics (with cascade=>true) and check.
Try to force the SQL to use HASH instead of nested loop.
Isolate the slow parts of the query and fix them individually.

Sandeep Singh Bajwa

-----Original Message-----
From: oracle-l-bounce_at_freelists.org On Behalf Of Zabair Ahmed
Sent: Tuesday, September 06, 2011 8:59 AM
To: [email protected]
Subject: tuning sql queries....

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

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

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

reply | permalink

Michael Dinh

at Sep 6, 2011 at 4:21 pm

⇧

Thinking out loud here.

I would create SQL Plan Baseline in the fast environment, export baseline, import baseline to slow environment.

I know this does not answers your question how to diagnose the issue. However, it does reduce the chance of different execution path for SQL.

Michael Dinh

Disparity Breaks Automation (DBA)

NOTICE OF CONFIDENTIALITY - This material is intended for the use of the individual or entity to which it is addressed, and may contain information that is privileged, confidential and exempt from disclosure under applicable laws. BE FURTHER ADVISED THAT THIS EMAIL MAY CONTAIN PROTECTED HEALTH INFORMATION (PHI). BY ACCEPTING THIS MESSAGE, YOU ACKNOWLEDGE THE FOREGOING, AND AGREE AS FOLLOWS: YOU AGREE TO NOT DISCLOSE TO ANY THIRD PARTY ANY PHI CONTAINED HEREIN, EXCEPT AS EXPRESSLY PERMITTED AND ONLY TO THE EXTENT NECESSARY TO PERFORM YOUR OBLIGATIONS RELATING TO THE RECEIPT OF THIS MESSAGE. If the reader of this email (and attachments) is not the intended recipient, you are hereby notified that any dissemination, distribution or copying of this communication is strictly prohibited. Please notify the sender of the error and delete the e-mail you received. Thank you.

-----Original Message-----
From: oracle-l-bounce_at_freelists.org On Behalf Of Zabair Ahmed
Sent: Tuesday, September 06, 2011 5:59 AM
To: [email protected]
Subject: tuning sql queries....

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

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

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

reply | permalink

Stephane Faroult

at Sep 6, 2011 at 5:28 pm

⇧

Several things make me uncomfortable here. An optimizer mode set to
ALL_ROWS to return 2 or 3 rows in the end (with only one GROUP BY in a
subquery). Give some free rein to Oracle and see what happens (after
having computed stats as advised by almost everyone).
Most worrying of all, the references to "rowid" to apparently try to
return the most recent stuff (I assume a "greater than" sign somewhere I
see a blank) - bold assumption that rowids are in the proper sequence!
In fact I fail to see how the subquery works, but it looks somewhat
dirty to me.
I'd try to run a single pass on pay_assignment_actions with an OR and a
CASE and an aggregate to get all the information needed at once. There
seems to be some redundancies between conditions in the main query and
the subquery. I have a vague feeling everything is done in the wrong way
(I mean that the driving tables aren't what they should be), which may
account for some optimizer distress.

HTH,

--
Stephane Faroult
RoughSea Ltd <http://www.roughsea.com>
Konagora <http://www.konagora.com>
RoughSea Channel on Youtube <http://www.youtube.com/user/roughsealtd>

On 09/06/2011 02:59 PM, 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 timef105720 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^(TM)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
********************************************************************************

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

reply | permalink

Job Miller

at Sep 6, 2011 at 8:34 pm

⇧

�SQLT / COMPARE is designed to identify differences in two execution environments.

SQLT (SQLTXPLAIN) - Tool That Helps To Diagnose SQL Statements Performing Poorly [ID 215187.1]
COMPARE Method
Use this COMPARE method when you have two similar systems (SOURCES)
and the same SQL statement performs fine in one of them but not in the
other. This method helps to pin-point the differences between the two
SOURCES in terms of plans, metadata, CBO statistics, initialization
parameters and bug fix-control. SQLT must be installed first in both, and any of the main methods must have been used on the same SQL in both systems.

The compare can take place on any of the two SOURCES or on a 3rd
COMPARE system. The latter should contain the SQLT repositories of the
two SOURCES. To import a SQLT repository use the syntax provided in the
sqlt_99999_readme.html file generated by any of the main methods.

Once the COMPARE system contains the repositories from both SOURCES, execute sqlt/run/sqltcompare.sql connecting as SYS, SQLTXPLAIN or the application user. A list of STATEMENT_ID is presented, from which you choose which two SQLT stored executions you want to compare. Once you indicate the two STATEMENT_ID you are asked next for particular PLAN_HASH_VALUE from both SOURCES.
# cd sqlt/run
# sqlplus sqltxplain

SQL> START sqltcompare.sql [STATEMENT_ID 1] [STATEMENT_ID 2]
SQL> START sqltcompare.sql 92263 72597
SQL> START sqltcompare.sql

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

reply | permalink

Related Discussions

Discussion Navigation

view	thread \| post

Discussion Overview

group	oracle-l @
categories	oracle
posted	Sep 6, '11 at 12:59p
active	Sep 6, '11 at 8:34p
posts	9
users	8
website	oracle.com

responses	expanded	Hotkey: s
font	variable	Hotkey: f
user style	avatars	Hotkey: a

[Oracle-l] tuning sql queries....

Search Discussions

Related Discussions

8 users in discussion