Oracle Database Discussions

Hello,

Need help in analysing this performance issue. I ran the trace for a batch process which is taking a lot of time using Oradebug and now I have my file formated through tkprof
as tkprof *****.trc ****.prc sys=no sort=fchela,exeela,prsela

I suspect the degradation is due to db file sequential read. Need your valuable suggestion in fixing this performance issue. Many thanks in advance.

***************************************************************
1. How to find the root cause of this performance issue ?
2. What could have caused the db file sequential read wait event?
3. Why are the SQL's not having thier SQL ID?
4. If I wish to see the Explain Plan for the SQL how can I see it as these queries do not have SQl_Id's ?
5. Why some queries do not have the explain plan ? [like the 1st one pasted below]
#################################################################

I suspect the first 2 queries below as the culprits, Please help me investiagte this further.


Some of the areas of concern which I found in the tkprof o/p trace file are below:

Sort options: fchela exeela prsela
********************************************************************************
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 T_00 . "MBLNR" , T_00 . "BUDAT" , T_00 . "CPUTM" , T_01 . "SHKZG" ,
T_01 . "MENGE" , T_01 . "MEINS"
FROM
"MKPF" T_00 INNER JOIN "MSEG" T_01 ON T_01 . "MANDT" = :A0 AND T_00 .
"MANDT" = T_01 . "MANDT" AND T_00 . "MBLNR" = T_01 . "MBLNR" AND T_00 .
"MJAHR" = T_01 . "MJAHR" WHERE T_00 . "MANDT" = :A1 AND T_01 . "MATNR" =
:A2 AND ( T_00 . "BUDAT" > :A3 OR T_00 . "BUDAT" = :A4 AND T_00 . "CPUTM" >=
:A5 ) AND T_01 . "WERKS" = :A6 AND T_01 . "LGORT" = :A7


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 540 0.28 0.39 0 0 0 0
Fetch 540 270.28 9692.09 1013597 3026518 0 68
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1080 270.56 9692.48 1013597 3026518 0 68

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 27

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1015472 5.85 9564.86
SQL*Net message to client 541 0.00 0.00
SQL*Net message from client 541 0.01 0.78
latch: cache buffers chains 89 0.38 0.40
latch: object queue header operation 21 0.00 0.01
latch free 7 0.08 0.10
read by other session 1118 0.09 8.70
********************************************************************************

SELECT "MANDT" , "VKORG" , "VTWEG" , "MATNR" , "SPRAS" , "TXTMD"
FROM
"BIW_MVKET" WHERE "MANDT" = :A0 AND ( "SPRAS" = :A1 OR "SPRAS" = :A2 OR
"SPRAS" = :A3 )


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.01 0.01 0 0 0 0
Fetch 19 4.80 20.13 34274 37345 0 63590
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 21 4.81 20.14 34274 37345 0 63590

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 27

Rows Row Source Operation
------- ---------------------------------------------------
63590 HASH JOIN (cr=37345 pr=34274 pw=0 time=36573040 us)
63590 HASH JOIN (cr=12928 pr=12052 pw=0 time=192139 us)
39 TABLE ACCESS BY INDEX ROWID TVTA (cr=4 pr=3 pw=0 time=10131 us)
39 INDEX RANGE SCAN TVTA~0 (cr=1 pr=1 pw=0 time=4068 us)(object id 164712)
63590 INDEX FAST FULL SCAN MVKE~0 (cr=12924 pr=12049 pw=0 time=113562 us)(object id 88349)
1409746 TABLE ACCESS FULL MAKT (cr=24417 pr=22222 pw=0 time=12719574 us)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 19 0.00 0.00
db file sequential read 414 0.02 0.70
db file scattered read 1827 0.13 15.55
latch: object queue header operation 1 0.00 0.00
SQL*Net more data to client 46 0.00 0.00
SQL*Net message from client 19 0.16 0.30
********************************************************************************

SELECT "LABST"
FROM
"MARD" WHERE "MANDT" = :A0 AND "MATNR" = :A1 AND "WERKS" = :A2 AND "LGORT" =
:A3


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 543 0.15 0.19 0 0 0 0
Fetch 543 0.19 7.52 654 2169 0 540
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1086 0.34 7.72 654 2169 0 540

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 27

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 654 0.08 7.39
SQL*Net message to client 543 0.00 0.00
SQL*Net message from client 543 0.00 0.27
********************************************************************************
..

..

.
.
.
..
.
.
.


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1322 0.05 0.07 0 0 0 0
Execute 3476 0.50 0.62 1 0 61 12
Fetch 7827 0.44 9.53 1060 17100 0 6603
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 12625 0.99 10.22 1061 17100 61 6615

Misses in library cache during parse: 14
Misses in library cache during execute: 10

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1060 0.08 9.21

367 user SQL statements in session.
3471 internal SQL statements in session.
3838 SQL statements in session.
********************************************************************************
Trace file: s1p_ora_2278.trc
Trace file compatibility: 10.01.00
Sort options: fchela exeela prsela
18 sessions in tracefile.
2340 user SQL statements in trace file.
14763 internal SQL statements in trace file.
3838 SQL statements in trace file.
382 unique SQL statements in trace file.
1349455 lines in trace file.
10237 elapsed seconds in trace file.

Regards,
Valli