Friday, October 31, 2008

Standby log gap issue solved

We had a physical standby database that is behind the primary database for several days. We found that there were gaps. So we restored the archived logs from tape by RMAN to their original destination. Oracle is smart enough to automatically fetch those archived logs to the destination. And we don't need to register them at all on the standby ( our environment is 10g).

However, we found the MRP0 process status is always WAIT_FOR_LOG when issue the following sql:

SELECT PROCESS, STATUS,SEQUENCE#,BLOCK#,BLOCKS, DELAY_MINS FROM
V$MANAGED_STANDBY


Later I found out that in the alert log, there is a line showing:

Media Recovery Delayed for 479 minute(s) (thread 1 sequence 52361)

I reallized we have used the DELAY=480 attribute of the LOG_ARCHIVE_DEST_2 initialization parameter on the primary database to delay applying archived redo log files to the standby database.

So I tryied the following command which I found in the documentaton on the standby:

ALTER DATABASE RECOVER MANAGED STANDBY DATABASE NODELAY;

Oracle started the redo apply immediately. By this way we are able to catch up and solve this log missing and apply lag issue.

Wednesday, October 29, 2008

PL/SQL Exception - a simple test

Continue the effort to learn PL/SQL - This is about EXCEPTION, simple test.



denis@TEST10G> @exception_1
denis@TEST10G> rem This is the test case to test the following situation:
denis@TEST10G> rem
denis@TEST10G> rem 1. Not using any exception, which would result in an ORA-01403 error
denis@TEST10G> rem 2. Uisng predefined Oracle Database exception NO_DATA_FOUND
denis@TEST10G> rem 3. Using user-defined exception
denis@TEST10G> rem
denis@TEST10G>
denis@TEST10G>
denis@TEST10G> drop table t;

Table dropped.

denis@TEST10G>
denis@TEST10G> create table t
2 as
3 select
4 rownum empno,
5 a.object_name ename
6 from all_objects a
7 where rownum < 5000;

Table created.

denis@TEST10G>
denis@TEST10G>
denis@TEST10G> -- Case 1: exception not defined
denis@TEST10G>
denis@TEST10G> declare
2 emp_number integer :=5000;
3 emp_name varchar2(50);
4 begin
5 select ename into emp_name from t
6 where empno = emp_number; -- no such number
7 dbms_output.put_line('Employee name is ' || emp_name);
8 end;
9 /
declare
*
ERROR at line 1:
ORA-01403: no data found
ORA-06512: at line 5


denis@TEST10G>
denis@TEST10G>
denis@TEST10G> -- Case 2: using predefind Oracle exception
denis@TEST10G>
denis@TEST10G> declare
2 emp_number integer :=5000;
3 emp_name varchar2(50);
4 begin
5 select ename into emp_name from t
6 where empno = emp_number; -- no such number
7 dbms_output.put_line('Employee name is ' || emp_name);
8 exception
9 when no_data_found then
10 dbms_output.put_line('No such employee:' || emp_number);
11 end;
12 /
No such employee:5000

PL/SQL procedure successfully completed.

denis@TEST10G>
denis@TEST10G>
denis@TEST10G> -- Case 3: using user-defined exception
denis@TEST10G> -- declare it in the delcaration part of a block
denis@TEST10G> -- define it in the exception part of the block
denis@TEST10G>
denis@TEST10G> declare
2 emp_number integer;
3 emp_name varchar2(50);
4 empno_out_of_range exception;
5 begin
6 emp_number := 5000;
7 if emp_number > 4999 or emp_number < 1 then
8 raise empno_out_of_range;
9 else
10 select ename into emp_name from t
11 where empno = emp_number;
12 dbms_output.put_line('Employee name is ' || emp_name);
13 end if;
14 exception
15 when empno_out_of_range then
16 dbms_output.put_line('Employee number:' || emp_number ||
17 ' is out of range.');
18 end;
19 /
Employee number:5000 is out of range.

PL/SQL procedure successfully completed.

Monday, October 27, 2008

Identify and kill a blocking session - enq: TX - row lock contention

This post documented steps I have taken to identify and kill a blocking session:

1. Recived alert:

DBNAME:critical-Higher wait events:enq: TX - row lock contention-63(threshold 50)

2. Checking the wait events, find that the count for 'enq: TX - row lock contention' is high

  COUNT(*) EVENT                                         MAX(SECONDS_IN_WAIT)
---------- --------------------------------------------- --------------------
5753 SQL*Net message from client                                6048278
188 SQL*Net break/reset to client                                33425
149 enq: TX - row lock contention                                12274
20 rdbms ipc message                                            41691
1 Streams AQ: qmn slave idle wait                             556815
1 Streams AQ: waiting for messages in the queue                    5
1 Streams AQ: waiting for time management or cl                33106
eanup tasks
1 db file parallel write                                           0
1 direct path write                                                2
1 Streams AQ: qmn coordinator idle wait                      6184833
1 jobq slave wait                                                 18
1 os thread startup                                                0
1 pmon timer                                                   18795
1 smon timer                                                    5504
1 SQL*Net message to client                                        0


3. Checking locks:

Looks everyone is waiting for sid=7752

system@DBNAME> @qlocks

Lock                Time Held
SID Lock Type Requested Lock Held (minutes) Block
------ --------- --------- --------- --------- -----
7752 Trans     None      Exclusive       325 Yes
3994 Trans     Share     None            324 No
8305 Trans     Share     None            323 No
4922 Trans     Share     None            292 No
3977 Trans     Share     None            285 No
7668 Trans     Share     None            282 No
4379 Trans     Share     None            124 No
5423 Trans     Share     None              1 No
7611 Trans     Share     None              1 No
6080 Trans     Share     None              1 No
3843 Trans     Share     None              0 No
4731 Trans     Share     None              0 No

( truncated ...  total 116 rows )



system@DBNAME> @blocker

ADDR             KADDR               SID TY        ID1        ID2      LMODE    REQUEST      CTIME   Block
---------------- ---------------- ------ -- ---------- ---------- ---------- ---------- ---------- ----------
0000000516758030 00000005167581B8   7752 TX    3080222     128785          6          0      19544 ##########





4. Check the session sid=7752

system@DBNAME> @sess_by_sid
Enter value for sid: 7752

Shadow       Remote       Remote
SID-SERIAL   OS User  Username         Module         Process      Process      Machine              Logon Time      Status
------------ -------- ---------------- -------------- ------------ ------------ -------------------- --------------- --------
'7752,55822' doammw27 OLAMLOG                         8786         1234         dspcef07             10/26 13:42:04  INACTIVE





5. The following query shows that session sid=7752 is 19367 sec old, and the last call made by it is 19366 sec ago.

system@DBNAME> @trans_long_running.sql

ADDR             Status       UBAREC           START_SCN SYSDATE             START_DATE                SECS     RSSIZE   SID LAST_CALL_ET Status   Username         OS User  SHARABLE_MEM
---------------- -------- ---------- ------------------- ------------------- ------------------- ---------- ---------- ----- ------------ -------- ---------------- -------- ------------
0000000516758030 ACTIVE           13      10172725882034 2008-10-26 19:05:54 2008-10-26 13:43:07      19367    1171456  7752        19366 INACTIVE OLAMLOG          doammw27




6. After killing the session sid=7752, wait event showed as follows:

  COUNT(*) EVENT                                         MAX(SECONDS_IN_WAIT)
---------- --------------------------------------------- --------------------
5943 SQL*Net message from client                                6049401
188 SQL*Net break/reset to client                                34548
22 rdbms ipc message                                            42814
1 smon timer                                                     276
1 Streams AQ: waiting for time management or cl                34229
eanup tasks

1 jobq slave wait                                                 47
1 pmon timer                                                     283
1 Streams AQ: qmn slave idle wait                             557938
1 Streams AQ: qmn coordinator idle wait                      6185956
1 SQL*Net message to client                                        0
1 Streams AQ: waiting for messages in the queue                    5




####---------------------------------------------------------------------------
Appendix - scripts used:

$ cat event.sql
rem file: event.sql
rem
rem  Lists the Current Waits in the database.
rem  First Script to run in the database to debug performance issues.
rem  This query lists the Count of Sessions group by Wait Event, and
rem  sorted in Ascending Order.
rem  Look for Top 5 Wait events from this query.
rem  Also listed is the maximum time ( seconds) sessions
rem  have waited against a particular wait event. Count Information is
rem  more valuable than the Max time information.
rem
column event format a45
select count(*), event, max(seconds_in_wait) from v$session_wait
group by event
order by 1 desc
/

####---------------------------------------------------------------------------

$ cat qlocks.sql
clear columns
clear computes
clear breaks

set linesize 240
set pagesize 40

column sid      format 99999    heading "SID"
column locktype format A9       heading "Lock Type"
column lockreq  format A9       heading "Lock     Requested"
column lockheld format A9       heading "Lock Held"
column timeheld format 9999999  heading "Time Held(minutes)"
column block    format a5       heading "Block"


select /* RULE */ l.sid sid,
decode(l.type,'TM','DML','TX','Trans','UL','User',l.type) locktype,
decode(l.request,0,'None',1,'Null',2,'Row-S',3,'Row-X',4,'Share',5,'S/Row-X',6,'Exclusive') lockreq,
decode(l.lmode,0,'None',1,'Null',2,'Row-S',3,'Row-X',4,'Share',5,'S/Row-X',6,'Exclusive') lockheld,
l.ctime/60 timeheld,
decode(l.block,0,'No',1,'Yes') block
from v$lock l
where l.request != 0 or l.block != 0
order by l.id1, l.lmode desc, l.ctime desc
/

####---------------------------------------------------------------------------
$ cat blocker.sql
select * from v$lock where block > 0
/

####---------------------------------------------------------------------------
$ cat sess_by_sid.sql
set linesize 250
set pagesize 1000
set verify off

column SidSerial        format a12      heading "SID-SERIAL"
column sid      format 9999     heading "SID"
column serial   format 99999    heading "Serial "
column osuser   format a8       heading "OS User"
column username format a16      heading "Username"
column module   format a14      heading "Module"
column spid     format 999999   heading "ShadowProcess"
column process  format 999999   heading "RemoteProcess"
column machine  format a20      heading "RemoteMachine"
column time     format a15      heading "Logon Time"
column status   format a8       heading "Status"


select ''''||s.sid||','||s.serial# ||'''' SidSerial,
--select s.sid sid ,
--s.serial# serial,
s.osuser                 osuser,
s.username               username,
s.module                 module,
p.spid                   spid,
s.process                process,
s.machine                machine,
to_char(s.logon_time, 'mm/dd hh24:mi:ss') time,
s.status                 status
from v$session s, v$process p
where s.paddr = p.addr (+)
and s.sid = &sid
/

####---------------------------------------------------------------------------

$ cat trans_long_running.sql
column start_scn format 999999999999999999
select
t.addr,
t.status,
t.UBAREC,
t.start_scn,
SYSDATE,
t.start_date,
(
(SYSDATE - t.start_date) * 86400
) secs,
r.rssize,
s.sid,
s.last_call_et,
s.status,
s.username,
s.osuser,
sa.sharable_mem
from
v$transaction t
join v$rollstat r on t.xidusn = r.usn
join v$session s on s.saddr = t.ses_addr
left outer join v$sqlarea sa on s.sql_address = sa.address
where s.sid = 7752
/


Wednesday, October 22, 2008

Oracle built-in functions: SUBSTR and INSTR

If we want to restore a RMAN backup to a different host and the path in the new host are different from those in the original host, we will have to use the 'set newname for datafile ' statment to change the file name. This test case demonstrated the use of SUBSTR and INSTR function and how to use them to generate the 'set newname for datafile' statement dynamically.


 

denis@TEST10G> @substr_instr.sql
denis@TEST10G> rem substr_instr.sql
denis@TEST10G> rem ref: http://www.psoug.org/reference/substr_instr.html
denis@TEST10G>
denis@TEST10G> set echo on
denis@TEST10G>
denis@TEST10G> SELECT SUBSTR('Take the first four characters', 1, 4) FIRST_FOUR
2 FROM dual;

FIRS
----
Take

denis@TEST10G>
denis@TEST10G> SELECT SUBSTR('Take the first four characters', 16, 4) MIDDLE_FOUR
2 FROM dual;

MIDD
----
four

denis@TEST10G>
denis@TEST10G>
denis@TEST10G> SELECT SUBSTR('Take the first four characters', 16) SIXTEEN_TO_END
2 FROM dual;

SIXTEEN_TO_END
---------------
four characters

denis@TEST10G>
denis@TEST10G> SELECT SUBSTR('Take the first four characters', -4) FINAL_FOUR
2 FROM dual;

FINA
----
ters

denis@TEST10G>
denis@TEST10G>
denis@TEST10G> SELECT INSTR('Take the first four characters', 'a', 1, 1) FOUND_1
2 FROM dual;

FOUND_1
----------
2

denis@TEST10G>
denis@TEST10G> SELECT INSTR('Take the first four characters', 'a', 1, 2) FOUND_2
2 FROM dual;

FOUND_2
----------
23

denis@TEST10G>
denis@TEST10G> SELECT INSTR('Take the first four characters', 'four', 1, 1) MCHARS
2 FROM dual;

MCHARS
----------
16

denis@TEST10G>
denis@TEST10G> SELECT INSTR('Take the first four characters', 'a', -1, 1) REV_SRCH
2 FROM dual;

REV_SRCH
----------
25

denis@TEST10G>
denis@TEST10G> SELECT INSTR('Take the first four characters', 'a', -1, 2) REV_TWO
2 FROM dual;

REV_TWO
----------
23

denis@TEST10G>
denis@TEST10G> -- Take up to the character before the first comma
denis@TEST10G> SELECT SUBSTR('abc,def,ghi', 1 ,INSTR('abc,def,ghi', ',', 1, 1)-1)
2 FROM dual;

SUB
---
abc

denis@TEST10G>
denis@TEST10G> -- List parsing center value
denis@TEST10G> -- Take the value between the commas
denis@TEST10G> SELECT SUBSTR('abc,def,ghi', INSTR('abc,def,ghi',',', 1, 1)+1,
2 INSTR('abc,def,ghi',',',1,2)-INSTR('abc,def,ghi',',',1,1)-1)
3 FROM dual;

SUB
---
def

denis@TEST10G>
denis@TEST10G> -- List parsing last value
denis@TEST10G> -- Take the value after the last comma
denis@TEST10G> SELECT SUBSTR('abc,def,ghi', INSTR('abc,def,ghi',',', 1, 2)+1)
2 FROM dual;

SUB
---
ghi

denis@TEST10G>
denis@TEST10G>
denis@TEST10G> -- test the case that restoring a databsase to a different host and with different path name
denis@TEST10G> -- using RMAN. Demonstrate how to create 'set new name' statments
denis@TEST10G>
denis@TEST10G> set linesize 400
denis@TEST10G> drop table t;

Table dropped.

denis@TEST10G> create table t(file_name varchar2(100));

Table created.

denis@TEST10G> insert into t values('/opt/app/wcmdb02/ora01/P3CM1D1/dbf/idx500cP0CMD_7.dbf');

1 row created.

denis@TEST10G> insert into t values('/opt/app/wcmdb02/ora03/P3CM1D1/dbf/usersP0CMD_1.dbf');

1 row created.

denis@TEST10G> commit;

Commit complete.

denis@TEST10G>
denis@TEST10G> select 'set newname for datafile ' || ''''||file_name||'''' ||
2 lpad('to ', 60-length(file_name)) || ''''||
3 '/opt/app/cm2cmdb' || substr(file_name,instr(file_name,'/',1,4), 6) ||'/P0CMD' ||
4 substr(file_name, instr(file_name, '/', -1, 2) ) || '''' || ';'
5 from t;

'SETNEWNAMEFORDATAFILE'||''''||FILE_NAME||''''||LPAD('TO',60-LENGTH(FILE_NAME))||''''||'/OPT/APP/CM2CMDB'||SUBSTR(FILE_NAME,INSTR(FILE_NAME,'/',1,4),6
------------------------------------------------------------------------------------------------------------------------------------------------------
------------------------------------------------------------------------------------------------------------------------------------------------------

set newname for datafile '/opt/app/wcmdb02/ora01/P3CM1D1/dbf/idx500cP0CMD_7.dbf' to '/opt/app/cm2cmdb/ora01/P0CMD/dbf/idx500cP0CMD_7.dbf';
set newname for datafile '/opt/app/wcmdb02/ora03/P3CM1D1/dbf/usersP0CMD_1.dbf' to '/opt/app/cm2cmdb/ora03/P0CMD/dbf/usersP0CMD_1.dbf';

denis@TEST10G>

Tuesday, October 21, 2008

Tablespace usage info from DBA_TABLESPACE_USAGE_METRICS view inconsistent with other methods

In the following test, for the same tablespace:PAC_TLGP02M, we obtained different used percent info between method 1 and 2.


Database version:



system@TESTDB> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.2.0 - 64bi
PL/SQL Release 10.2.0.2.0 - Production
CORE 10.2.0.2.0 Production
TNS for HPUX: Version 10.2.0.2.0 - Production
NLSRTL Version 10.2.0.2.0 - Production




Method 1:



system@TESTDB> @tbs_usage_metrics_10g.sql
system@TESTDB> select * from dba_tablespace_usage_metrics
2 order by used_percent desc;

TABLESPACE_NAME USED_SPACE TABLESPACE_SIZE USED_PERCENT
------------------------------ ---------- --------------- ------------
PAC_TLGP02M 2726400 2816000 96.8181818
PAC_TLGP52M 4894720 5120256 95.5952202
PAC_TBS11L 88857600 95207040 93.3309133
PAC_CHARGE_HIST_TAXES51 40320000 43499776 92.6901325
PAC_MEMO01M 33925120 37633152 90.1469003

( .... truncated ....)



Method 2



system@TESTDB>
system@TESTDB> @l2/freespace
system@TESTDB> clear columns
system@TESTDB> clear computes
system@TESTDB> clear breaks
system@TESTDB>
system@TESTDB> set verify off
system@TESTDB> set linesize 180
system@TESTDB> set pagesize 40
system@TESTDB>
system@TESTDB> compute sum of fsize on dummy
system@TESTDB> compute sum of totalfree on dummy
system@TESTDB> break on dummy
system@TESTDB>
system@TESTDB> column dummy noprint
system@TESTDB> column ts format a18 heading "Tablespace"
system@TESTDB> column fn format a65 heading "File Name"
system@TESTDB> column fid format 9999 heading "File|ID "
system@TESTDB> column fsize format 99,999,999 heading "File |Size (MB)"
system@TESTDB> column maxfree format 999,999.9 heading "Largest |Free |Frag (MB)"
system@TESTDB> column totalfree format 99,999,999 heading "Total |Free (MB)"
system@TESTDB> column pctused format 999.99 heading "% Used"
system@TESTDB>
system@TESTDB> select null dummy,
2 a.tablespace_name ts,
3 a.file_name fn,
4 a.file_id fid,
5 nvl(a.bytes/1024/1024,0) fsize,
6 nvl(max(b.bytes/1024/1024),0) maxfree,
7 nvl(sum(b.bytes/1024/1024),0) totalfree,
8 (1 - nvl(sum(b.bytes),0)/a.bytes)*100 pctused
9 from dba_data_files a, dba_free_space b
10 where a.tablespace_name = upper('&tablespace')
11 and a.file_id = b.file_id (+)
12 group by a.tablespace_name, a.file_name, a.file_id, a.bytes
13 order by substr(a.file_name, instr(a.file_name,'/',-1) + 1, 40)
14 /
Enter value for tablespace: PAC_TLGP02M

Largest
File File Free Total
Tablespace File Name ID Size (MB) Frag (MB) Free (MB) % Used
------------------ ----------------------------------------------------------------- ----- ----------- ---------- ----------- -------
PAC_TLGP02M /ora_44a_02/ORACLE/TESTDB/dbf/tlgp02mTESTDB_01.dbf 179 22,000 690.0 8,680 60.55
----------- -----------
22,000 8,680



The following query list all tablespace usage by method 2

system@TESTDB> set echo on
system@TESTDB> @tf2
system@TESTDB> col tsname format a24 justify c heading 'Tablespace'
system@TESTDB> col nfrags format 9,999,990 justify c heading 'Free|Frags'
system@TESTDB> col mxfrag format 999,990.999 justify c heading 'Largest|Free Frag'
system@TESTDB> col totsiz format 9,999,990.999 justify c heading 'Total|Mbytes'
system@TESTDB> col avasiz format 9,999,990.999 justify c heading 'Available|Mbytes'
system@TESTDB> col pctusd format 990.99 justify c heading 'Percent|Used'
system@TESTDB>
system@TESTDB> set pagesize 200
system@TESTDB> set linesize 120
system@TESTDB>
system@TESTDB> select
2 total.tablespace_name tsname,
3 count(free.bytes) nfrags,
4 round(nvl(max(free.bytes)/1048576,0),2) mxfrag,
5 total.bytes/1048576 totsiz,
6 round(nvl(sum(free.bytes)/1048576,0),2) avasiz,
7 round((1-nvl(sum(free.bytes),0)/total.bytes)*100,2) pctusd
8 from
9 (select tablespace_name, sum(bytes) bytes
10 from dba_data_files
11 group by tablespace_name) total,
12 dba_free_space free
13 where
14 --total.tablespace_name in ('TBS01S','TBS01M','TBS01L','TBS51S','TBS51M','TBS51L')
15 --and
16 total.tablespace_name = free.tablespace_name(+)
17 group by
18 total.tablespace_name,
19 total.bytes
20 order by 6 desc, 1
21 /

Free Largest Total Available Percent
Tablespace Frags Free Frag Mbytes Mbytes Used
------------------------ ---------- ------------ -------------- -------------- -------
PAC_TBS11L 32 21,200.000 743,805.000 49,400.000 93.36
PAC_CHARGE_HIST_TAXES51 5 11,200.000 339,842.000 24,500.000 92.79
PAC_MEMO01M 4 24,160.000 294,009.000 28,920.000 90.16
PAC_TBS61L 5 11,400.000 360,014.000 36,000.000 90.00
PAC_CHARGE_TAXES51 2 2,210.000 40,768.000 4,150.000 89.82
PAC_TBS61M 31 10,570.000 175,771.000 18,030.000 89.74

( ... truncated ... )
PAC_TLGP52M 1,348 1,760.000 40,002.000 15,230.000 61.93
PAC_TLGP02M 800 690.000 22,000.000 8,680.000 60.55

( ... truncated .... )

Sunday, October 19, 2008

Unable to find library 'libsqlplus.sl'

One user account on a Unix server, which is not belong to DBA group, is unable to use sqlplus, the following message received when typing sqlplus on the command line:

/usr/lib/pa20_64/dld.sl: Unable to find library 'libsqlplus.sl'.

This issue was fixed by changing permession of libsqlplus.sql under $ORACLE_HOME/lib from 750 to 755.

Since before yesterday, this user account did not have problem. And last night we did the patch on this server, possibly the permission was changed during the patching.

Search internet there is a thread of disscussion quite similar to our situation.

Saturday, October 18, 2008

Why waiting for 'db file sequential read' whereas plan shows FTS?

Application team reported that a query usually run less than 1 hour now took almost 3 hour and still not finish. This query is only a select statement against one table. I checked the execution plan of this query it is a very simple FTS. But when check the wait event, it is waiting for 'db file sequential read', which usually means index scan.

The application team killed the session and re-run the query some time later, and this time it was finished much faster.

Later performance team provided a nice explaination, first of all they provided the following query result:



select x.* , (select file_name from dba_data_files where file_id=p1) name from (
select p1, count(*) cnt
from v$active_session_history where sql_id='8xnhck4a6d400' and event='db file sequential read'
group by p1 order by 2 desc
)x


P1 CNT NAME
----------------------- ---------------------- --------------------------------------------------------
114 188 /ora_36a_04/ORACLE/DBNAME/dbf/undoDBNAME_6.dbf
2 188 /ora_36a_01/ORACLE/DBNAME/dbf/undoDBNAME_1.dbf
162 176 /ora_36a_05/ORACLE/DBNAME/dbf/undoDBNAME_13.dbf
33 173 /ora_36a_02/ORACLE/DBNAME/dbf/undoDBNAME_2.dbf
113 172 /ora_36a_05/ORACLE/DBNAME/dbf/undoDBNAME_5.dbf
95 170 /ora_36a_03/ORACLE/DBNAME/dbf/undoDBNAME_9.dbf
112 169 /ora_36a_04/ORACLE/DBNAME/dbf/undoDBNAME_5.dbf
105 168 /ora_36a_04/ORACLE/DBNAME/dbf/undoDBNAME_3.dbf
96 167 /ora_36a_05/ORACLE/DBNAME/dbf/undoDBNAME_10.dbf
97 166 /ora_36a_05/ORACLE/DBNAME/dbf/undoDBNAME_11.dbf
94 165 /ora_36a_05/ORACLE/DBNAME/dbf/undoDBNAME_8.dbf
93 161 /ora_36a_04/ORACLE/DBNAME/dbf/undoDBNAME_7.dbf
111 161 /ora_36a_04/ORACLE/DBNAME/dbf/undoDBNAME_4.dbf



This query undoubtly demonstrate that the wait for 'db file sequntial read' is due to read from undo tablespace blocks.

They further expained:

The difference between the first and second run is that on the first (slow) run when query started , it appears there was a lot of DML activity was going on against CH_OBJECTS table - possibly involving longer than normal running non-committed transactions. This made Oracle perform a lot of extra I/O against the UNDO segments in order to maintain a read consistent image of the data true to the moment the query was kicked off.

When the query was kicked off the second time, the abnormal DML activity had already completed and there were no reads from UNDO segments, just the normal serial full scan occurred.

It is a great learning experience for me. Particularly what insterested to me is the way they query the v$active_session_history view. I did the following
exercise in another database:




system@DB2NAME> select distinct(event) from v$active_session_history where sql_id='axuuxsm4p8hct';

EVENT
----------------------------------------------------------------

reliable message
os thread startup
direct path read
PX Deq: Signal ACK


system@DB2NAME> select p1, p1text, count(*) from v$active_session_history
where sql_id='axuuxsm4p8hct' and event='direct path read' group by p1, p1text;

P1 P1TEXT COUNT(*)
---------- -------------------------------- ----------
540 file number 1
407 file number 2
193 file number 1

system@DB2NAME> select file_name from dba_data_files where file_id=540;

FILE_NAME
------------------------------------------------------------------------------------------------------------------------
/ora_44a_04/ORACLE/DB2NAME/dbf/tlgp11mDB2NAME_06.dbf

system@DB2NAME> select file_name from dba_data_files where file_id=407;

FILE_NAME
------------------------------------------------------------------------------------------------------------------------
/ora_44a_07/ORACLE/DB2NAME/dbf/tlgp11mDB2NAME_05.dbf



1 select x.*, (select file_name from dba_data_files where file_id=p1) from
2 (
3 select p1, count(*) from v$active_session_history where sql_id='axuuxsm4p8hct' and event='direct path read' group by p1
4* ) x
system@DB2NAME> /

P1 COUNT(*)
---------- ----------
(SELECTFILE_NAMEFROMDBA_DATA_FILESWHEREFILE_ID=P1)
------------------------------------------------------------------------------------------------------------------------
407 2
/ora_44a_07/ORACLE/DB2NAME/dbf/tlgp11mDB2NAME_05.dbf

193 1
/ora_44a_02/ORACLE/DB2NAME/dbf/tlgp11mDB2NAME_01.dbf

540 1
/ora_44a_04/ORACLE/DB2NAME/dbf/tlgp11mDB2NAME_06.dbf