Also note the
very high "query" number (i.e. buffers gotten for consistent read).
That could account for a lot of the i/o, which is the proximate cause of the
loooong elapsed time. From the (to use one of Lisa's favorite terms) doco
(for 9i):
Read
Consistency
Your system might spend excessive time rolling
back changes to blocks in order to maintain a consistent view. Consider the
following scenarios:
If there are
many small transactions and an active long-running query is running in the
background on the same table where the changes are happening, then the query
might need to roll back those changes often, in order to obtain a
read-consistent image of the table. Compare the following
V$SYSSTAT statistics to determine whether this is happening:
consistent
changes statistic indicates the number of times a database block has
rollback entries applied to perform a consistent read on the block.
Workloads that produce a great deal of consistent changes can consume a
great deal of resources.
consistent
gets statistic counts the number of logical reads in consistent mode.
If there are few
very, large rollback segments, then your system could be spending a lot of
time rolling back the transaction table during delayed block cleanout in order
to find out exactly which SCN a transaction was committed. The ratio of the
following V$SYSSTAT statistics should be close to 1:
ratio = transaction tables consistent reads undo records applied /
transaction tables consistent read rollbacks
A solution is to create more, smaller
rollback segments, or to use automatic undo management.
Paul Baumgartel MortgageSight Holdings,
LLC pbaumgartel_at_mortgagesight.com
<FONT face=Tahoma
size=2>-----Original Message-----From: Koivu, Lisa
[mailto:lisa.koivu_at_efairfield.com]Sent: Thursday, August 30, 2001
12:47 PMTo: Multiple recipients of list ORACLE-LSubject:
RE: Tkprof output
Lee,
This query seems suspect
UPDATE VM_LIVE.SINGLE_CUSTOMER_HISTORY SCH SET
VISIBLE=1WHERE ACXIOM_CUSTOMER_KEY = :b1 AND VERSION_NO =
:b2
because of this
call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0
0Execute 39562
4.55 7.22
10897
118687
1
1Fetch
0 0.00
0.00
0
0
0 0-------
------ -------- ---------- ---------- ---------- ----------
----------total 39562
4.55 7.22
10897
118687
1 1
It's reading a ton of blocks to operate on ONE
record. What's the table structure here? What's the index
structure? Cardinality?
The buffer gets in the other queries are suspect
too. What's your blocksize? It's reading a ton of blocks to arrive
at the result.
-----Original Message----- <FONT
face=Arial size=1>From: <FONT face=Arial
size=1>Robertson Lee - lerobe [SMTP:lerobe_at_acxiom.co.uk] <FONT
face=Arial size=1>Sent: <FONT face=Arial
size=1>Thursday, August 30, 2001 11:56 AM <FONT face=Arial
size=1>To: <FONT face=Arial
size=1>Multiple recipients of list ORACLE-L <FONT face=Arial
size=1>Subject: <FONT
face=Arial size=1>Tkprof output
Apologies for the length of the mail.
This query is
running for a mad amount of time, anyone any ideas. <FONT
face=Arial> Code and tkprof out put
shown below. <FONT face=Arial
size=2>Huge TIA <FONT
face=Arial size=2>Lee (who must learn more about such things !!!)
DECLARE
CURSOR TEMP_CDS ISSELECT
ACXIOM_CUSTOMER_KEY,
VERSION_NO,
ADDRESS_OCCUPANCY_KEYFROM
CUSTOMER_DETAIL_SOURCEWHERE VISIBLE=1; <FONT
face=Arial> COUNTER
NUMBER(8); <FONT face=Courier
size=1>BEGIN COUNTER:=0; FOR I IN
TEMP_CDS LOOP
UPDATE
&SCHEMA..SINGLE_CUSTOMER
SC SET
VISIBLE =
1
WHERE
ACXIOM_CUSTOMER_KEY=I.ACXIOM_CUSTOMER_KEY
AND VERSION_NO
=I.VERSION_NO; <FONT
face=Courier size=1> UPDATE
&SCHEMA..SINGLE_CUSTOMER_HISTORY
SCH
SET VISIBLE =
1
WHERE
ACXIOM_CUSTOMER_KEY=I.ACXIOM_CUSTOMER_KEY
AND VERSION_NO
=I.VERSION_NO; <FONT
face=Courier size=1> UPDATE
&SCHEMA..ADDRESS_OCCUPANCY
AO SET
VISIBLE =
1
WHERE ADDRESS_OCCUPANCY_KEY = I.ADDRESS_OCCUPANCY_KEY; <FONT
face=Arial> <FONT face=Courier
size=1> COUNTER := COUNTER +
1; IF (COUNTER =
50000)
THEN
COUNTER:=0;
COMMIT; END IF; END
LOOP; COMMIT;
Sort options: prsela exeela
fchela ********************************************************************************count
- number of times OCI procedure was
executedcpu = cpu time in seconds
executingelapsed = elapsed time in seconds
executingdisk = number of physical reads of
buffers from diskquery = number of buffers gotten for
consistent readcurrent = number of buffers gotten in current mode
(usually for update)rows = number of rows
processed by the fetch or execute
call********************************************************************************
UPDATE
VM_LIVE.SINGLE_CUSTOMER SC SET
VISIBLE=1WHERE ACXIOM_CUSTOMER_KEY = :b1 AND VERSION_NO =
:b2 <FONT face=Courier
size=1>call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0
0Execute 39562
15.51 398.98
56555 181085
40672
39562Fetch
0 0.00
0.00
0
0
0 0-------
------ -------- ---------- ---------- ---------- ----------
----------total 39562
15.51 398.98
56555 181085
40672 39562 <FONT
face=Arial> Misses in library
cache during parse: 0Misses in library cache during execute:
1Optimizer goal: CHOOSEParsing user id: 39
(VM_LIVE) (recursive depth: 1) <FONT
face=Arial> <FONT face=Courier
size=1>Rows Execution Plan-------
---------------------------------------------------
0 UPDATE STATEMENT GOAL:
CHOOSE 0 UPDATE OF
'SINGLE_CUSTOMER' 0
TABLE ACCESS (BY INDEX ROWID) OF
'SINGLE_CUSTOMER'
0 INDEX (UNIQUE SCAN) OF 'SINGLE_CUSTOMER_PK'
(UNIQUE) <FONT face=Courier
size=1>********************************************************************************
UPDATE
VM_LIVE.ADDRESS_OCCUPANCY AO SET
VISIBLE=1WHERE ADDRESS_OCCUPANCY_KEY = :b1 <FONT
face=Arial> <FONT face=Courier
size=1>call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0
0Execute 39562
12.57 186.88
57285 124038
40726
39562Fetch
0 0.00
0.00
0
0
0 0-------
------ -------- ---------- ---------- ---------- ----------
----------total 39562
12.57 186.88
57285 124038
40726 39562 <FONT
face=Arial> Misses in library
cache during parse: 0Optimizer goal: CHOOSEParsing user id: 39
(VM_LIVE) (recursive depth: 1) <FONT
face=Arial> <FONT face=Courier
size=1>Rows Execution Plan-------
---------------------------------------------------
0 UPDATE STATEMENT GOAL:
CHOOSE 0 UPDATE OF
'ADDRESS_OCCUPANCY' 0
INDEX (UNIQUE SCAN) OF 'I_ADDRESS_OCCUPANCY_I4' (UNIQUE) <FONT
face=Arial> <FONT face=Courier
size=1>********************************************************************************
UPDATE
VM_LIVE.SINGLE_CUSTOMER_HISTORY SCH SET
VISIBLE=1WHERE ACXIOM_CUSTOMER_KEY = :b1 AND VERSION_NO =
:b2 <FONT face=Courier
size=1>call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0
0Execute 39562
4.55 7.22
10897
118687
1
1Fetch
0 0.00
0.00
0
0
0 0-------
------ -------- ---------- ---------- ---------- ----------
----------total 39562
4.55 7.22
10897
118687
1 1
Misses in
library cache during parse: 0Optimizer goal: CHOOSEParsing user id:
39 (VM_LIVE) (recursive depth: 1) <FONT
face=Arial> <FONT face=Courier
size=1>Rows Execution Plan-------
---------------------------------------------------
0 UPDATE STATEMENT GOAL:
CHOOSE 0 UPDATE OF
'SINGLE_CUSTOMER_HISTORY'
0 INDEX (UNIQUE SCAN) OF 'SINGLE_CUSTOMER_HISTORY_PK'
(UNIQUE) <FONT face=Courier
size=1>********************************************************************************
SELECT
ACXIOM_CUSTOMER_KEY,VERSION_NO,ADDRESS_OCCUPANCY_KEY FROM CUSTOMER_DETAIL_SOURCE
WHERE VISIBLE = 1 <FONT
face=Courier size=1>call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0
0Execute 0
0.00
0.00
0
0
0
0Fetch 39562
1.51
2.04
392
39618
0 39562------- ------ --------
- ---------- ---------- ----------
----------total 39562
1.51
2.04
392
39618
0 39562 <FONT
face=Arial> Misses in library
cache during parse: 0Parsing user id: 39 (VM_LIVE)
(recursive depth: 1) <FONT
face=Arial> <FONT
face=Courier
size=1>********************************************************************************
OVERALL
TOTALS FOR ALL NON-RECURSIVE STATEMENTS <FONT
face=Arial> <FONT face=Courier
size=1>call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0
0Execute 0
0.00
0.00
0
0
0
0Fetch
0 0.00
0.00
0
0
0 0-------
------ -------- ---------- ---------- ---------- ----------
----------total
0 0.00
0.00
0
0
0 0
Misses in
library cache during parse: 0
OVERALL TOTALS FOR ALL RECURSIVE
STATEMENTS <FONT face=Courier
size=1>call
count cpu
elapsed
disk query
current rows-------
------ -------- ---------- ---------- ---------- ----------
----------Parse
0 0.00
0.00
0
0
0 0Execute
118686 32.63
593.08 124737
423810
81399 79125Fetch
39562 1.51
2.04
392
39618
0 39562------- ------ --------
- ---------- ---------- ----------
----------total 158248
34.14 595.12
125129 463428
81399 118687 <FONT
face=Arial> Misses in library
cache during parse: 0Misses in library cache during execute: 1
<FONT face=Courier
size=1> 4 user SQL statements in
session. 0 internal SQL statements in
session. 4 SQL statements in
session. 3 statements EXPLAINed in this
session.********************************************************************************Trace
file: ora_349778.trcTrace file compatibility: 7.03.02Sort options:
prsela exeela
fchela 1 session in
tracefile. 4 user SQL
statements in trace file. 0
internal SQL statements in trace
file. 4 SQL statements in
trace file. 4 unique SQL
statements in trace file. 3
SQL statements EXPLAINed using
schema:
VM_LIVE.prof$plan_table
Default table was
used.
Table was
created.
Table was dropped. 158286 lines in trace file.
The information contained in this
communication isconfidential, is intended only for the use of the
recipientnamed above, and may be legally privileged. If the readerof
this message is not the intended recipient, you arehereby notified that
any dissemination, distribution orcopying of this communication is
strictly prohibited.If you have received this communication in error,
pleasere-send this communication to the sender and delete
theoriginal message or any copy of it from your
computersystem.
Received on Thu Aug 30 2001 - 12:26:47 CDT
