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.

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.

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
/

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>

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 .... )

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.

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