-
Once again, please trace it, tkprof it, post relevant section *formatted* in code tags
Pablo (Paul) Berzukov
Author of Understanding Database Administration available at amazon and other bookstores.
Disclaimer: Advice is provided to the best of my knowledge but no implicit or explicit warranties are provided. Since the advisor explicitly encourages testing any and all suggestions on a test non-production environment advisor should not held liable or responsible for any actions taken based on the given advice.
-
Here is the tkprof output from Prod DB
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 3 418.00 408.20 0 2007 0 18
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 418.00 408.20 0 2007 0 18
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 59
Rows Row Source Operation
------- ---------------------------------------------------
18 SORT UNIQUE (cr=2007 pr=0 pw=0 time=408203515 us)
18 UNION-ALL (cr=2007 pr=0 pw=0 time=408203229 us)
16 HASH GROUP BY (cr=1501 pr=0 pw=0 time=401507299 us)
40910398 MERGE JOIN CARTESIAN (cr=1501 pr=0 pw=0 time=41230056 us)
799 HASH JOIN (cr=1388 pr=0 pw=0 time=279026 us)
18 NESTED LOOPS (cr=317 pr=0 pw=0 time=24642 us)
18 HASH JOIN (cr=297 pr=0 pw=0 time=24105 us)
18 HASH JOIN (cr=281 pr=0 pw=0 time=20113 us)
349 TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=0 pw=0 time=11490 us)
362 TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=0 pw=0 time=3385 us)
520 TABLE ACCESS FULL USER_DETAILS (cr=16 pr=0 pw=0 time=617 us)
18 TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=0 pw=0 time=485 us)
18 INDEX UNIQUE SCAN SYS_C006428 (cr=2 pr=0 pw=0 time=202 us)(object id 53935)
91120 TABLE ACCESS FULL OPERATING_FLIGHT_SCHEDULE (cr=1071 pr=0 pw=0 time=92685 us)
40910398 BUFFER SORT (cr=113 pr=0 pw=0 time=41018101 us)
51202 INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=0 pw=0 time=126 us)(object id 53929)
2 HASH GROUP BY (cr=506 pr=0 pw=0 time=6695159 us)
716828 MERGE JOIN CARTESIAN (cr=506 pr=0 pw=0 time=846405 us)
14 HASH JOIN (cr=393 pr=0 pw=0 time=39909 us)
18 NESTED LOOPS (cr=317 pr=0 pw=0 time=19998 us)
18 HASH JOIN (cr=297 pr=0 pw=0 time=19481 us)
18 HASH JOIN (cr=281 pr=0 pw=0 time=17258 us)
349 TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=0 pw=0 time=11286 us)
362 TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=0 pw=0 time=3386 us)
520 TABLE ACCESS FULL USER_DETAILS (cr=16 pr=0 pw=0 time=623 us)
18 TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=0 pw=0 time=480 us)
18 INDEX UNIQUE SCAN SYS_C006428 (cr=2 pr=0 pw=0 time=201 us)(object id 53935)
8297 TABLE ACCESS FULL MARKETING_FLIGHT_SCHEDULE (cr=76 pr=0 pw=0 time=8408 us)
716828 BUFFER SORT (cr=113 pr=0 pw=0 time=808224 us)
51202 INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=0 pw=0 time=108 us)(object id 53929)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 0.00 0.01
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 3 418.00 408.20 0 2007 0 18
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 418.00 408.20 0 2007 0 18
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 6 0.00 0.00
SQL*Net message from client 6 94.81 119.61
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 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
2 user SQL statements in session.
0 internal SQL statements in session.
2 SQL statements in session.
********************************************************************************
Trace file: cms_ora_21054.trc
Trace file compatibility: 10.01.00
Sort options: default
1 session in tracefile.
2 user SQL statements in trace file.
0 internal SQL statements in trace file.
2 SQL statements in trace file.
2 unique SQL statements in trace file.
95 lines in trace file.
433 elapsed seconds in trace file.
What's next after 10g?
-
This is the tkprof output from Dev DB
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.28 0.27 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 3 1274.82 1286.75 1547 2007 0 18
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 5 1275.10 1287.03 1547 2007 0 18
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 60
Rows Row Source Operation
------- ---------------------------------------------------
18 SORT UNIQUE (cr=2007 pr=1547 pw=0 time=1286759124 us)
18 UNION-ALL (cr=2007 pr=1547 pw=0 time=1286758687 us)
16 HASH GROUP BY (cr=1501 pr=1473 pw=0 time=1262504407 us)
40910398 MERGE JOIN CARTESIAN (cr=1501 pr=1473 pw=0 time=945084723 us)
799 HASH JOIN (cr=1388 pr=1365 pw=0 time=3818244 us)
18 NESTED LOOPS (cr=317 pr=296 pw=0 time=162166 us)
18 HASH JOIN (cr=297 pr=290 pw=0 time=140385 us)
18 HASH JOIN (cr=281 pr=276 pw=0 time=101273 us)
349 TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=187 pw=0 time=59551 us)
362 TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=89 pw=0 time=23938 us)
520 TABLE ACCESS FULL USER_DETAILS (cr=16 pr=14 pw=0 time=25311 us)
18 TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=6 pw=0 time=21200 us)
18 INDEX UNIQUE SCAN SYS_C005605 (cr=2 pr=1 pw=0 time=18785 us)(object id 51935)
91120 TABLE ACCESS FULL OPERATING_FLIGHT_SCHEDULE (cr=1071 pr=1069 pw=0 time=1756633 us)
40910398 BUFFER SORT (cr=113 pr=108 pw=0 time=369042788 us)
51202 INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=108 pw=0 time=531161 us)(object id 51929)
2 HASH GROUP BY (cr=506 pr=74 pw=0 time=24251876 us)
716828 MERGE JOIN CARTESIAN (cr=506 pr=74 pw=0 time=19063303 us)
14 HASH JOIN (cr=393 pr=74 pw=0 time=365136 us)
18 NESTED LOOPS (cr=317 pr=0 pw=0 time=49047 us)
18 HASH JOIN (cr=297 pr=0 pw=0 time=46978 us)
18 HASH JOIN (cr=281 pr=0 pw=0 time=28911 us)
349 TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=0 pw=0 time=6541 us)
362 TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=0 pw=0 time=4419 us)
520 TABLE ACCESS FULL USER_DETAILS (cr=16 pr=0 pw=0 time=5327 us)
18 TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=0 pw=0 time=1465 us)
18 INDEX UNIQUE SCAN SYS_C005605 (cr=2 pr=0 pw=0 time=570 us)(object id 51935)
8297 TABLE ACCESS FULL MARKETING_FLIGHT_SCHEDULE (cr=76 pr=74 pw=0 time=138494 us)
716828 BUFFER SORT (cr=113 pr=0 pw=0 time=7234330 us)
51202 INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=0 pw=0 time=460892 us)(object id 51929)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
db file sequential read 8 0.02 0.11
db file scattered read 120 0.11 0.92
SQL*Net message from client 3 0.33 0.42
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.28 0.27 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 3 1274.82 1286.75 1547 2007 0 18
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 1275.10 1287.03 1547 2007 0 18
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 6 0.00 0.00
SQL*Net message from client 6 369.38 384.59
db file sequential read 8 0.02 0.11
db file scattered read 120 0.11 0.92
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 37 0.04 0.03 0 0 0 0
Execute 389 0.32 0.44 0 0 0 0
Fetch 652 0.18 0.47 49 1319 0 2731
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1078 0.56 0.95 49 1319 0 2731
Misses in library cache during parse: 21
Misses in library cache during execute: 21
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 49 0.02 0.31
2 user SQL statements in session.
389 internal SQL statements in session.
391 SQL statements in session.
********************************************************************************
Trace file: 10gstd_ora_900.trc
Trace file compatibility: 10.01.00
Sort options: default
1 session in tracefile.
2 user SQL statements in trace file.
389 internal SQL statements in trace file.
391 SQL statements in trace file.
23 unique SQL statements in trace file.
3753 lines in trace file.
1303 elapsed seconds in trace file.
What's next after 10g?
-
format it with code tags!
-
Hi
Just a wild shot there in the dark.
Whats the value of this initialization parameter
filesystemio_options
on Both the dev and Prod environment.
regards
Hrishy
-
On Prod DB,
filesystemio_options=ASYNCH
On Dev DB, filesystemio_options does not have any value.
However, disk_asynch_io=TRUE on both DB.
What's next after 10g?
-
But still it should show at least db file scatterd and sequential read in wait events in prod. I'm not sure why it's not showing. BTW, did u raise a Oracle SR for this issue?
-
Hi all,
Thanks for all your advise.
I have finally found the root cause to my new server performance issue.
Please refer to metalink note: 781763.1
"Subject: Migration from fast single threaded CPU machine to CMT UltraSPARC T1 and T2 results in increased CPU report ".
I am experiencing exactly the same problem mentioned in this note.
My Sun box is using the newer CMT processor 1.2GHz and I think its 4cores with 8 threads each. OS and Oracle will see 32 cpu in total. Our application code is ported over from a 2 core Sun SPARC IV 1.6Ghz server. I believe the legacy code was not written for parallel execution even.
Each time I run my test query, only 1 out of 32 CPU will be busy at 100% for full 6+mins.
I have also run the same test query on different servers and below are the results:
AIX, 2Ghz x 2core CPU, Oracle 10g SE - 1min 30secs
Solaris 10, 1.6Ghz x 2core CPU Sparc IV, Oracle 10g EE - 2mins 50secs
Wintel notebook, 2Ghz x 2 core CPU, Oracle 10g SE - 1mins 40secs
Solaris 10, 1.2Ghz x 32 cores Sparc T2 (CMT), Oracle 10g SE - 6+ mins
Cheers
Orac
What's next after 10g?
Posting Permissions
- You may not post new threads
- You may not post replies
- You may not post attachments
- You may not edit your posts
-
Forum Rules
|
Click Here to Expand Forum to Full Width
|