Strange Performance Issue on 10gR2

Hi,

I have this strange performance issue which I have been troubleshooting for a week and is getting not very far.

My users complain to me that all queries on this newly setup database is running much slower than their dev DB.

New Production DB
- is on a Sun box Solaris 10, 32 cores CPU, 32GB RAM, Sun storage
- Oracle 10gR2 64 bit 10.2.0.1.0 Standard Edition
- SGA_TARGET = 1.5GB
- PGA_AGGREGATE_TARGET = 1GB
- optimizer_mode = ALL_ROWS

Dev DB
- a normal MS Windows XP notebook
- Oracle 10gR2 10.2.0.1.0 Standard Edition
- SGA_TARGET = 270Mb
- PGA_AGGREGATE_TARGET = 89Mb
- optimizer_mode = ALL_ROWS

Dataset for the testing is exactly the same on both system as they were from the same source.

The query run on Dev DB took only 1min 40secs, while the same query run took 5+mins on Prod DB.
Explain plan and statistics are the same on both systems.

Below is the results taken from SQLPLUS with "set autotrace on" and "set timing on"

Prod DB:
18 rows selected.

Elapsed: 00:05:22.72

Execution Plan
----------------------------------------------------------
Plan hash value: 820129149

-----------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 137M| 17G| | 12M (2)| 43:04:06 |
| 1 | SORT UNIQUE | | 137M| 17G| 37G| 8634K (46)| 28:46:49 |
| 2 | UNION-ALL | | | | | | |
| 3 | HASH GROUP BY | | 75M| 9G| 20G| 4782K (2)| 15:56:29 |
| 4 | MERGE JOIN CARTESIAN | | 75M| 9G| | 35273 (6)| 00:07:04 |
|* 5 | HASH JOIN | | 1559 | 213K| | 316 (5)| 00:00:04 |
| 6 | NESTED LOOPS | | 82 | 10414 | | 71 (5)| 00:00:01 |
|* 7 | HASH JOIN | | 82 | 8364 | | 68 (5)| 00:00:01 |
|* 8 | HASH JOIN | | 148 | 11544 | | 62 (4)| 00:00:01 |
|* 9 | TABLE ACCESS FULL | FLIGHT_SCHEDULE_PROCESING | 148 | 6808 | | 42 (3)| 00:00:01 |
|* 10 | TABLE ACCESS FULL | PERMIT_LICENSE | 355 | 11360 | | 19 (0)| 00:00:01 |
| 11 | TABLE ACCESS FULL | USER_DETAILS | 520 | 12480 | | 5 (0)| 00:00:01 |
| 12 | TABLE ACCESS BY INDEX ROWID| AIRLINE_MASTER | 1 | 25 | | 1 (0)| 00:00:01 |
|* 13 | INDEX UNIQUE SCAN | SYS_C006428 | 1 | | | 0 (0)| 00:00:01 |
| 14 | TABLE ACCESS FULL | OPERATING_FLIGHT_SCHEDULE | 89240 | 1132K| | 243 (4)| 00:00:03 |
| 15 | BUFFER SORT | | 48714 | | | 2408K (2)| 08:01:43 |
| 16 | INDEX FAST FULL SCAN | ACTION_ID_FK | 48714 | | | 22 (5)| 00:00:01 |
| 17 | HASH GROUP BY | | 61M| 8165M| 16G| 3851K (2)| 12:50:21 |
| 18 | MERGE JOIN CARTESIAN | | 61M| 8165M| | 28231 (6)| 00:05:39 |
|* 19 | HASH JOIN | | 1255 | 171K| | 90 (5)| 00:00:02 |
| 20 | NESTED LOOPS | | 82 | 10414 | | 71 (5)| 00:00:01 |
|* 21 | HASH JOIN | | 82 | 8364 | | 68 (5)| 00:00:01 |
|* 22 | HASH JOIN | | 148 | 11544 | | 62 (4)| 00:00:01 |
|* 23 | TABLE ACCESS FULL | FLIGHT_SCHEDULE_PROCESING | 148 | 6808 | | 42 (3)| 00:00:01 |
|* 24 | TABLE ACCESS FULL | PERMIT_LICENSE | 355 | 11360 | | 19 (0)| 00:00:01 |
| 25 | TABLE ACCESS FULL | USER_DETAILS | 520 | 12480 | | 5 (0)| 00:00:01 |
| 26 | TABLE ACCESS BY INDEX ROWID| AIRLINE_MASTER | 1 | 25 | | 1 (0)| 00:00:01 |
|* 27 | INDEX UNIQUE SCAN | SYS_C006428 | 1 | | | 0 (0)| 00:00:01 |
| 28 | TABLE ACCESS FULL | MARKETING_FLIGHT_SCHEDULE | 8264 | 104K| | 19 (6)| 00:00:01 |
| 29 | BUFFER SORT | | 48714 | | | 1939K (2)| 06:28:00 |
| 30 | INDEX FAST FULL SCAN | ACTION_ID_FK | 48714 | | | 22 (5)| 00:00:01 |
-----------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

5 - access("OFS"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
7 - access("UD"."USER_ID"="PL"."ATMAN_USERID")
8 - access("FSP"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
9 - filter("FSP"."SEASON_CODE"='NS0909')
10 - filter("PL"."PERMIT_OR_LICENSE"='L' AND "PL"."DDGO"='1')
13 - access("AM"."AIRLINE_ID"="FSP"."AIRLINE_ID")
19 - access("OFS"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
21 - access("UD"."USER_ID"="PL"."ATMAN_USERID")
22 - access("FSP"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
23 - filter("FSP"."SEASON_CODE"='NS0909')
24 - filter("PL"."PERMIT_OR_LICENSE"='L' AND "PL"."DDGO"='1')
27 - access("AM"."AIRLINE_ID"="FSP"."AIRLINE_ID")


Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2007 consistent gets
0 physical reads
0 redo size
3008 bytes sent via SQL*Net to client
480 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
3 sorts (memory)
0 sorts (disk)
18 rows processed

Dev DB:

18 rows selected.

Elapsed: 00:01:41.48

Execution Plan
----------------------------------------------------------
Plan hash value: 4057473448

----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
----------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 137M| 17G| | 17M (1)| 58:00:23 |
| 1 | SORT UNIQUE | | 137M| 17G| 37G| 11M (46)| 38:44:20 |
| 2 | UNION-ALL | | | | | | |
| 3 | HASH GROUP BY | | 75M| 9G| 20G| 6437K (1)| 21:27:25 |
| 4 | MERGE JOIN CARTESIAN | | 75M| 9G| | 35148 (6)| 00:07:02 |
|* 5 | HASH JOIN | | 1559 | 213K| | 315 (5)| 00:00:04 |
| 6 | NESTED LOOPS | | 82 | 10414 | | 71 (5)| 00:00:01 |
|* 7 | HASH JOIN | | 82 | 8364 | | 67 (3)| 00:00:01 |
|* 8 | HASH JOIN | | 148 | 11544 | | 62 (4)| 00:00:01 |
|* 9 | TABLE ACCESS FULL | FLIGHT_SCHEDULE_PROCESING | 148 | 6808 | | 42 (3)| 00:00
|* 10 | TABLE ACCESS FULL | PERMIT_LICENSE | 355 | 11360 | | 19 (0)| 00:00:01 |
| 11 | TABLE ACCESS FULL | USER_DETAILS | 520 | 12480 | | 5 (0)| 00:00:01 |
| 12 | TABLE ACCESS BY INDEX ROWID| AIRLINE_MASTER | 1 | 25 | | 1 (0)
|* 13 | INDEX UNIQUE SCAN | SYS_C005605 | 1 | | | 0 (0)| 00:00:01 |
| 14 | TABLE ACCESS FULL | OPERATING_FLIGHT_SCHEDULE | 89240 | 1132K| | 242 (4)|
| 15 | BUFFER SORT | | 48714 | | | 3235K (1)| 10:47:11 |
| 16 | INDEX FAST FULL SCAN | ACTION_ID_FK | 48714 | | | 22 (5)| 00:00
| 17 | HASH GROUP BY | | 61M| 8165M| 16G| 5184K (1)| 17:16:55 |
| 18 | MERGE JOIN CARTESIAN | | 61M| 8165M| | 28130 (6)| 00:05:38 |
|* 19 | HASH JOIN | | 1255 | 171K| | 90 (5)| 00:00:02 |
| 20 | NESTED LOOPS | | 82 | 10414 | | 71 (5)| 00:00:01 |
|* 21 | HASH JOIN | | 82 | 8364 | | 67 (3)| 00:00:01 |
|* 22 | HASH JOIN | | 148 | 11544 | | 62 (4)| 00:00:01 |
|* 23 | TABLE ACCESS FULL | FLIGHT_SCHEDULE_PROCESING | 148 | 6808 | | 42 (3)| 00:00
|* 24 | TABLE ACCESS FULL | PERMIT_LICENSE | 355 | 11360 | | 19 (0)| 00:00:01 |
| 25 | TABLE ACCESS FULL | USER_DETAILS | 520 | 12480 | | 5 (0)| 00:00:01 |
| 26 | TABLE ACCESS BY INDEX ROWID| AIRLINE_MASTER | 1 | 25 | | 1 (0)
|* 27 | INDEX UNIQUE SCAN | SYS_C005605 | 1 | | | 0 (0)| 00:00:01 |
| 28 | TABLE ACCESS FULL | MARKETING_FLIGHT_SCHEDULE | 8264 | 104K| | 19 (6)|
| 29 | BUFFER SORT | | 48714 | | | 2606K (1)| 08:41:17 |
| 30 | INDEX FAST FULL SCAN | ACTION_ID_FK | 48714 | | | 22 (5)| 00:00
----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

5 - access("OFS"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
7 - access("UD"."USER_ID"="PL"."ATMAN_USERID")
8 - access("FSP"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
9 - filter("FSP"."SEASON_CODE"='NS0909')
10 - filter("PL"."PERMIT_OR_LICENSE"='L' AND "PL"."DDGO"='1')
13 - access("AM"."AIRLINE_ID"="FSP"."AIRLINE_ID")
19 - access("OFS"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
21 - access("UD"."USER_ID"="PL"."ATMAN_USERID")
22 - access("FSP"."SCHEDULE_NO"="PL"."SCHEDULE_NO")
23 - filter("FSP"."SEASON_CODE"='NS0909')
24 - filter("PL"."PERMIT_OR_LICENSE"='L' AND "PL"."DDGO"='1')
27 - access("AM"."AIRLINE_ID"="FSP"."AIRLINE_ID")


Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2007 consistent gets
0 physical reads
0 redo size
2760 bytes sent via SQL*Net to client
396 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
3 sorts (memory)
0 sorts (disk)
18 rows processed

When the query is executed on Prod DB, I observed that the particular oracle unix session is taking up 1 CPU out of the 32 and is working 100% for the full 5+mins. If I kick off multiple SQLPLUS sessions running the same query, multiple CPUs will be working 100% each too.
I observe this CPU info from unix command "mpstat 2 100".

This Prod server had OS hardening done to it before.
However, I could not determine if that is the root cause as there was not performance test run performed before and after hardening.

Since the explain plan and stats are the same on both Prod and Dev DBs, I would assume we can rule out the Oracle optimizer and bad SQL on this 2 systems. The query uses a costly UNION. Even though it is recommended to use UNION ALL instead of UNION in the query, it did not improve the response time on Prod DB.

Appreciate any advise as to how to narrow down the root cause of my performance issue.

Cheers
Orac

Trace the query in both environments, compare wait events.

Tracing was already done with event 10046.
On the Dev DB, the only wait events were "db file sequential read & db file scattered read" + the usual "SQL*Net message".
On Prod DB, there wasn't any wait besides the usual "SQL*Net message".

Can u answer below questions
1. In prod is your file system in SAN and Dev file system is local?
2. What abt data, are they same in prod and dev?

Quote:

---

Originally Posted by oracbase

On the Dev DB, the only wait events were "db file sequential read & db file scattered read" + the usual "SQL*Net message".
On Prod DB, there wasn't any wait besides the usual "SQL*Net message".

---

Check again prod trace, no read wait events means query didn't even attempted to read.

Please post tkprof of relevant section of both dev and prod traces.

Hi,

Prod DB is using SUN storage and UFS filesystem with kaio. (i think this is not recommended disk config for Sun/Oracle right?)

Dev DB is just a local disk on notebook.

Data is the same on Prod and Dev DB. I imported them from the same source.
From the source DB, the query only takes 2.5mins having same explain plan.
Although the source DB is also SUN box(less powerful in terms of CPU and memory) and UFS filesystem, but I hear from my sysadmin that it is using Veritas Volume Manager to manage the source storage.

I have been running the AWR report a few times with the same query execution.
I noticed that there is significant "control file parallel write".
When the query is running, iostat also shows that the disk where controlfiles and redo logfiles reside is having more I/O than the other disks with datafiles.

I am suspecting it this performance issue is due to Sun async I/O on the filesystem.

Can someone confirm that my suspicion is correct?

Cheers
Orac

Here is the trace 10046 output for Prod DB.

select /* 10046_prod */ am.airline_name,fsp.schedule_no,fsp.fs_serial_number,min(ofs.effective_period_from) Effective_period,fsp.created_date,
(fsp.created_date+5) Date_To_Clear,pl.serial_number_document,ud.user_name,fsp.OPERATING_OR_MARKETING,fsp.airline_id
from Airline_master am, flight_schedule_procesing fsp,action_table at,
operating_flight_schedule ofs,permit_license pl,user_details ud where ofs.schedule_no = pl.schedule_no and
fsp.schedule_no=pl.schedule_no and am.airline_id = fsp.airline_id and ud.user_id = pl.atman_userid
and pl.ddgo='1' AND fsp.SEASON_CODE='NS0909' and pl.permit_or_license='L'
group by am.airline_name,fsp.schedule_no,fsp.fs_serial_number,fsp.created_date,pl.serial_number_document,
ud.user_name ,fsp.OPERATING_OR_MARKETING,fsp.airline_id
UNION select am.airline_name,fsp.schedule_no,fsp.fs_serial_number,min(ofs.effective_period_from) Effective_period,
fsp.created_date,(fsp.created_date+5) Date_To_Clear,pl.serial_number_document,ud.user_name ,
fsp.OPERATING_OR_MARKETING,fsp.airline_id from Airline_master am, flight_schedule_procesing fsp,action_table at,
MARKETING_FLIGHT_SCHEDULE ofs,permit_license pl,user_details ud
where ofs.schedule_no = pl.schedule_no and fsp.schedule_no=pl.schedule_no
and am.airline_id = fsp.airline_id and ud.user_id = pl.atman_userid and pl.ddgo='1'
AND fsp.SEASON_CODE='NS0909' and pl.permit_or_license= 'L'
group by am.airline_name,fsp.schedule_no,fsp.fs_serial_number,fsp.created_date,
pl.serial_number_document,ud.user_name ,fsp.OPERATING_OR_MARKETING,fsp.airline_id
order by Date_To_Clear desc,Effective_Period desc
END OF STMT
PARSE #2:c=0,e=545,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3592666218283
EXEC #2:c=0,e=416,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3592666219654
WAIT #2: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3592666219788
*** 2009-05-22 10:16:20.345
FETCH #2:c=418000000,e=408203242,p=0,cr=2007,cu=0,mis=0,r=1,dep=0,og=1,tim=3593074423177
WAIT #2: nam='SQL*Net message from client' ela= 1333 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593074427198
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593074427365
FETCH #2:c=0,e=249,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,tim=3593074427577
WAIT #2: nam='SQL*Net message from client' ela= 9444 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593074437142
WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593074437268
FETCH #2:c=0,e=129,p=0,cr=0,cu=0,mis=0,r=2,dep=0,og=1,tim=3593074437374
WAIT #2: nam='SQL*Net message from client' ela= 2446 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593074440331
STAT #2 id=1 cnt=18 pid=0 pos=1 obj=0 op='SORT UNIQUE (cr=2007 pr=0 pw=0 time=408203515 us)'
STAT #2 id=2 cnt=18 pid=1 pos=1 obj=0 op='UNION-ALL (cr=2007 pr=0 pw=0 time=408203229 us)'
STAT #2 id=3 cnt=16 pid=2 pos=1 obj=0 op='HASH GROUP BY (cr=1501 pr=0 pw=0 time=401507299 us)'
STAT #2 id=4 cnt=40910398 pid=3 pos=1 obj=0 op='MERGE JOIN CARTESIAN (cr=1501 pr=0 pw=0 time=41230056 us)'
STAT #2 id=5 cnt=799 pid=4 pos=1 obj=0 op='HASH JOIN (cr=1388 pr=0 pw=0 time=279026 us)'
STAT #2 id=6 cnt=18 pid=5 pos=1 obj=0 op='NESTED LOOPS (cr=317 pr=0 pw=0 time=24642 us)'
STAT #2 id=7 cnt=18 pid=6 pos=1 obj=0 op='HASH JOIN (cr=297 pr=0 pw=0 time=24105 us)'
STAT #2 id=8 cnt=18 pid=7 pos=1 obj=0 op='HASH JOIN (cr=281 pr=0 pw=0 time=20113 us)'
STAT #2 id=9 cnt=349 pid=8 pos=1 obj=53959 op='TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=0 pw=0 time=11490 us)'
STAT #2 id=10 cnt=362 pid=8 pos=2 obj=53995 op='TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=0 pw=0 time=3385 us)'
STAT #2 id=11 cnt=520 pid=7 pos=2 obj=54012 op='TABLE ACCESS FULL USER_DETAILS (cr=16 pr=0 pw=0 time=617 us)'
STAT #2 id=12 cnt=18 pid=6 pos=2 obj=53934 op='TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=0 pw=0 time=485 us)'
STAT #2 id=13 cnt=18 pid=12 pos=1 obj=53935 op='INDEX UNIQUE SCAN SYS_C006428 (cr=2 pr=0 pw=0 time=202 us)'
STAT #2 id=14 cnt=91120 pid=5 pos=2 obj=53982 op='TABLE ACCESS FULL OPERATING_FLIGHT_SCHEDULE (cr=1071 pr=0 pw=0 time=92685 us)'
STAT #2 id=15 cnt=40910398 pid=4 pos=2 obj=0 op='BUFFER SORT (cr=113 pr=0 pw=0 time=41018101 us)'
STAT #2 id=16 cnt=51202 pid=15 pos=1 obj=53929 op='INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=0 pw=0 time=126 us)'
STAT #2 id=17 cnt=2 pid=2 pos=2 obj=0 op='HASH GROUP BY (cr=506 pr=0 pw=0 time=6695159 us)'
STAT #2 id=18 cnt=716828 pid=17 pos=1 obj=0 op='MERGE JOIN CARTESIAN (cr=506 pr=0 pw=0 time=846405 us)'
STAT #2 id=19 cnt=14 pid=18 pos=1 obj=0 op='HASH JOIN (cr=393 pr=0 pw=0 time=39909 us)'
STAT #2 id=20 cnt=18 pid=19 pos=1 obj=0 op='NESTED LOOPS (cr=317 pr=0 pw=0 time=19998 us)'
STAT #2 id=21 cnt=18 pid=20 pos=1 obj=0 op='HASH JOIN (cr=297 pr=0 pw=0 time=19481 us)'
STAT #2 id=22 cnt=18 pid=21 pos=1 obj=0 op='HASH JOIN (cr=281 pr=0 pw=0 time=17258 us)'
STAT #2 id=23 cnt=349 pid=22 pos=1 obj=53959 op='TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=0 pw=0 time=11286 us)'
STAT #2 id=24 cnt=362 pid=22 pos=2 obj=53995 op='TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=0 pw=0 time=3386 us)'
STAT #2 id=25 cnt=520 pid=21 pos=2 obj=54012 op='TABLE ACCESS FULL USER_DETAILS (cr=16 pr=0 pw=0 time=623 us)'
STAT #2 id=26 cnt=18 pid=20 pos=2 obj=53934 op='TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=0 pw=0 time=480 us)'
STAT #2 id=27 cnt=18 pid=26 pos=1 obj=53935 op='INDEX UNIQUE SCAN SYS_C006428 (cr=2 pr=0 pw=0 time=201 us)'
STAT #2 id=28 cnt=8297 pid=19 pos=2 obj=53975 op='TABLE ACCESS FULL MARKETING_FLIGHT_SCHEDULE (cr=76 pr=0 pw=0 time=8408 us)'
STAT #2 id=29 cnt=716828 pid=18 pos=2 obj=0 op='BUFFER SORT (cr=113 pr=0 pw=0 time=808224 us)'
STAT #2 id=30 cnt=51202 pid=29 pos=1 obj=53929 op='INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=0 pw=0 time=108 us)'
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593074442812
*** 2009-05-22 10:17:57.462
WAIT #0: nam='SQL*Net message from client' ela= 94818409 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=3593169261305
XCTEND rlbk=0, rd_only=1

Here is the trace 10046 output for Dev DB.

PARSING IN CURSOR #2 len=1585 dep=0 uid=60 oct=3 lid=60 tim=4844269580 hv=4130183277 ad='18e267a8'
select /* 10046_dev */ am.airline_name,fsp.schedule_no,fsp.fs_serial_number,min(ofs.effective_period_from) Effective_period,fsp.created_date,
(fsp.created_date+5) Date_To_Clear,pl.serial_number_document,ud.user_name,fsp.OPERATING_OR_MARKETING,fsp.airline_id
from Airline_master am, flight_schedule_procesing fsp,action_table at,
operating_flight_schedule ofs,permit_license pl,user_details ud where ofs.schedule_no = pl.schedule_no and
fsp.schedule_no=pl.schedule_no and am.airline_id = fsp.airline_id and ud.user_id = pl.atman_userid
and pl.ddgo='1' AND fsp.SEASON_CODE='NS0909' and pl.permit_or_license='L'
group by am.airline_name,fsp.schedule_no,fsp.fs_serial_number,fsp.created_date,pl.serial_number_document,
ud.user_name ,fsp.OPERATING_OR_MARKETING,fsp.airline_id
UNION select am.airline_name,fsp.schedule_no,fsp.fs_serial_number,min(ofs.effective_period_from) Effective_period,
fsp.created_date,(fsp.created_date+5) Date_To_Clear,pl.serial_number_document,ud.user_name ,
fsp.OPERATING_OR_MARKETING,fsp.airline_id from Airline_master am, flight_schedule_procesing fsp,action_table at,
MARKETING_FLIGHT_SCHEDULE ofs,permit_license pl,user_details ud
where ofs.schedule_no = pl.schedule_no and fsp.schedule_no=pl.schedule_no
and am.airline_id = fsp.airline_id and ud.user_id = pl.atman_userid and pl.ddgo='1'
AND fsp.SEASON_CODE='NS0909' and pl.permit_or_license= 'L'
group by am.airline_name,fsp.schedule_no,fsp.fs_serial_number,fsp.created_date,
pl.serial_number_document,ud.user_name ,fsp.OPERATING_OR_MARKETING,fsp.airline_id
order by Date_To_Clear desc,Effective_Period desc
END OF STMT
PARSE #2:c=843750,e=1233677,p=49,cr=1319,cu=0,mis=1,r=0,dep=0,og=1,tim=4844269569
EXEC #2:c=0,e=354,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=4844270322
WAIT #2: nam='SQL*Net message to client' ela= 8 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4844270407
WAIT #2: nam='db file sequential read' ela= 19146 file#=4 block#=12044 blocks=1 obj#=51959 tim=4844291907
WAIT #2: nam='db file scattered read' ela= 3427 file#=4 block#=12045 blocks=16 obj#=51959 tim=4844295590
WAIT #2: nam='db file scattered read' ela= 2932 file#=4 block#=12061 blocks=16 obj#=51959 tim=4844298999
....................
.....................
(lots of similar WAIT for 'db file scattered read' lines)
....................
....................
WAIT #2: nam='db file scattered read' ela= 861 file#=4 block#=785 blocks=8 obj#=51929 tim=4848209699
WAIT #2: nam='db file scattered read' ela= 832 file#=4 block#=794 blocks=7 obj#=51929 tim=4848269278
WAIT #2: nam='db file scattered read' ela= 1096 file#=4 block#=801 blocks=8 obj#=51929 tim=4848321229
WAIT #2: nam='db file scattered read' ela= 588 file#=4 block#=810 blocks=4 obj#=51929 tim=4848380713
*** 2009-05-22 10:10:42.237
WAIT #2: nam='db file scattered read' ela= 26178 file#=4 block#=13915 blocks=16 obj#=51982 tim=5305514047
*** 2009-05-22 10:13:21.920
WAIT #2: nam='db file scattered read' ela= 25565 file#=4 block#=13931 blocks=16 obj#=51982 tim=5465586645
*** 2009-05-22 10:14:09.928
WAIT #2: nam='db file scattered read' ela= 24855 file#=4 block#=13947 blocks=14 obj#=51982 tim=5513657089
*** 2009-05-22 10:17:29.012
WAIT #2: nam='db file scattered read' ela= 15669 file#=4 block#=13963 blocks=16 obj#=51982 tim=5712986353
*** 2009-05-22 10:18:37.422
WAIT #2: nam='db file scattered read' ela= 23656 file#=4 block#=13979 blocks=16 obj#=51982 tim=5781468584
*** 2009-05-22 10:20:23.414
WAIT #2: nam='db file scattered read' ela= 40395 file#=4 block#=13995 blocks=16 obj#=51982 tim=5887508279
*** 2009-05-22 10:22:40.931
WAIT #2: nam='db file scattered read' ela= 41340 file#=4 block#=14011 blocks=14 obj#=51982 tim=6025035684
*** 2009-05-22 10:24:02.698
WAIT #2: nam='db file sequential read' ela= 21001 file#=4 block#=12619 blocks=1 obj#=51975 tim=6106848462
WAIT #2: nam='db file scattered read' ela= 792 file#=4 block#=12620 blocks=5 obj#=51975 tim=6106849532
WAIT #2: nam='db file scattered read' ela= 784 file#=4 block#=12625 blocks=8 obj#=51975 tim=6106869092
WAIT #2: nam='db file scattered read' ela= 1030 file#=4 block#=12634 blocks=7 obj#=51975 tim=6106900005
WAIT #2: nam='db file scattered read' ela= 782 file#=4 block#=12641 blocks=8 obj#=51975 tim=6106926075
WAIT #2: nam='db file scattered read' ela= 726 file#=4 block#=12650 blocks=7 obj#=51975 tim=6106955718
WAIT #2: nam='db file scattered read' ela= 796 file#=4 block#=12657 blocks=8 obj#=51975 tim=6106982712
WAIT #2: nam='db file scattered read' ela= 715 file#=4 block#=12666 blocks=7 obj#=51975 tim=6107011906
WAIT #2: nam='db file scattered read' ela= 783 file#=4 block#=12673 blocks=8 obj#=51975 tim=6107037802
WAIT #2: nam='db file scattered read' ela= 941 file#=4 block#=12682 blocks=7 obj#=51975 tim=6107067545
*** 2009-05-22 10:24:26.841
WAIT #2: nam='db file scattered read' ela= 31789 file#=4 block#=12689 blocks=8 obj#=51975 tim=6131010935
FETCH #2:c=1274828125,e=1286758667,p=1547,cr=2007,cu=0,mis=0,r=1,dep=0,og=1,tim=6131029148
WAIT #2: nam='SQL*Net message from client' ela= 34676 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6131064072
WAIT #2: nam='SQL*Net message to client' ela= 7 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6131064203
FETCH #2:c=0,e=368,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=1,tim=6131064529
WAIT #2: nam='SQL*Net message from client' ela= 330776 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6131395398
WAIT #2: nam='SQL*Net message to client' ela= 7 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6131395574
FETCH #2:c=0,e=150,p=0,cr=0,cu=0,mis=0,r=2,dep=0,og=1,tim=6131395670
WAIT #2: nam='SQL*Net message from client' ela= 60068 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6131456111
STAT #2 id=1 cnt=18 pid=0 pos=1 obj=0 op='SORT UNIQUE (cr=2007 pr=1547 pw=0 time=1286759124 us)'
STAT #2 id=2 cnt=18 pid=1 pos=1 obj=0 op='UNION-ALL (cr=2007 pr=1547 pw=0 time=1286758687 us)'
STAT #2 id=3 cnt=16 pid=2 pos=1 obj=0 op='HASH GROUP BY (cr=1501 pr=1473 pw=0 time=1262504407 us)'
STAT #2 id=4 cnt=40910398 pid=3 pos=1 obj=0 op='MERGE JOIN CARTESIAN (cr=1501 pr=1473 pw=0 time=945084723 us)'
STAT #2 id=5 cnt=799 pid=4 pos=1 obj=0 op='HASH JOIN (cr=1388 pr=1365 pw=0 time=3818244 us)'
STAT #2 id=6 cnt=18 pid=5 pos=1 obj=0 op='NESTED LOOPS (cr=317 pr=296 pw=0 time=162166 us)'
STAT #2 id=7 cnt=18 pid=6 pos=1 obj=0 op='HASH JOIN (cr=297 pr=290 pw=0 time=140385 us)'
STAT #2 id=8 cnt=18 pid=7 pos=1 obj=0 op='HASH JOIN (cr=281 pr=276 pw=0 time=101273 us)'
STAT #2 id=9 cnt=349 pid=8 pos=1 obj=51959 op='TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=187 pw=0 time=59551 us)'
STAT #2 id=10 cnt=362 pid=8 pos=2 obj=51995 op='TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=89 pw=0 time=23938 us)'
STAT #2 id=11 cnt=520 pid=7 pos=2 obj=52012 op='TABLE ACCESS FULL USER_DETAILS (cr=16 pr=14 pw=0 time=25311 us)'
STAT #2 id=12 cnt=18 pid=6 pos=2 obj=51934 op='TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=6 pw=0 time=21200 us)'
STAT #2 id=13 cnt=18 pid=12 pos=1 obj=51935 op='INDEX UNIQUE SCAN SYS_C005605 (cr=2 pr=1 pw=0 time=18785 us)'
STAT #2 id=14 cnt=91120 pid=5 pos=2 obj=51982 op='TABLE ACCESS FULL OPERATING_FLIGHT_SCHEDULE (cr=1071 pr=1069 pw=0 time=1756633 us)'
STAT #2 id=15 cnt=40910398 pid=4 pos=2 obj=0 op='BUFFER SORT (cr=113 pr=108 pw=0 time=369042788 us)'
STAT #2 id=16 cnt=51202 pid=15 pos=1 obj=51929 op='INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=108 pw=0 time=531161 us)'
STAT #2 id=17 cnt=2 pid=2 pos=2 obj=0 op='HASH GROUP BY (cr=506 pr=74 pw=0 time=24251876 us)'
STAT #2 id=18 cnt=716828 pid=17 pos=1 obj=0 op='MERGE JOIN CARTESIAN (cr=506 pr=74 pw=0 time=19063303 us)'
STAT #2 id=19 cnt=14 pid=18 pos=1 obj=0 op='HASH JOIN (cr=393 pr=74 pw=0 time=365136 us)'
STAT #2 id=20 cnt=18 pid=19 pos=1 obj=0 op='NESTED LOOPS (cr=317 pr=0 pw=0 time=49047 us)'
STAT #2 id=21 cnt=18 pid=20 pos=1 obj=0 op='HASH JOIN (cr=297 pr=0 pw=0 time=46978 us)'
STAT #2 id=22 cnt=18 pid=21 pos=1 obj=0 op='HASH JOIN (cr=281 pr=0 pw=0 time=28911 us)'
STAT #2 id=23 cnt=349 pid=22 pos=1 obj=51959 op='TABLE ACCESS FULL FLIGHT_SCHEDULE_PROCESING (cr=189 pr=0 pw=0 time=6541 us)'
STAT #2 id=24 cnt=362 pid=22 pos=2 obj=51995 op='TABLE ACCESS FULL PERMIT_LICENSE (cr=92 pr=0 pw=0 time=4419 us)'
STAT #2 id=25 cnt=520 pid=21 pos=2 obj=52012 op='TABLE ACCESS FULL USER_DETAILS (cr=16 pr=0 pw=0 time=5327 us)'
STAT #2 id=26 cnt=18 pid=20 pos=2 obj=51934 op='TABLE ACCESS BY INDEX ROWID AIRLINE_MASTER (cr=20 pr=0 pw=0 time=1465 us)'
STAT #2 id=27 cnt=18 pid=26 pos=1 obj=51935 op='INDEX UNIQUE SCAN SYS_C005605 (cr=2 pr=0 pw=0 time=570 us)'
STAT #2 id=28 cnt=8297 pid=19 pos=2 obj=51975 op='TABLE ACCESS FULL MARKETING_FLIGHT_SCHEDULE (cr=76 pr=74 pw=0 time=138494 us)'
STAT #2 id=29 cnt=716828 pid=18 pos=2 obj=0 op='BUFFER SORT (cr=113 pr=0 pw=0 time=7234330 us)'
STAT #2 id=30 cnt=51202 pid=29 pos=1 obj=51929 op='INDEX FAST FULL SCAN ACTION_ID_FK (cr=113 pr=0 pw=0 time=460892 us)'
WAIT #0: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6131457258
*** 2009-05-22 10:30:36.465
WAIT #0: nam='SQL*Net message from client' ela= 369383560 driver id=1413697536 #bytes=1 p3=0 obj#=51975 tim=6500840876
XCTEND rlbk=0, rd_only=1

Once again, please trace it, tkprof it, post relevant section *formatted* in code tags

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.

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.

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.

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