[20210326]Disk file operations IO与文件型数据库.txt

--//实际上这个问题困扰我很久，一直不知道为什么，我们生产系统主要运行在exadata上，遇到这个等待事件，当然不是主要的等待事
--//件。我一直不清楚为什么出现这样的情况，自己无法解析，花一些时间探究这个等待事件。
--//首先从文件型数据库谈起，然后再讲讲使用存储的rac，最后exadata，在写这篇blog时，我自己还是不明白我们生产系统为什么会出
--//现的现象。

1.环境：
SCOTT@book> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

2.一些简单介绍：
--//参考链接上的介绍：
Disk file operations I/O

This event is used to wait for disk file operations (for example, open, close, seek, and resize). It is also used for
miscellaneous I/O operations such as block dumps and password file accesses.

--//此事件用于等待磁盘文件操作(例如，打开、关闭、查找和调整大小)。 它还用于各种I/O操作，如块转储和密码文件访问。

FileOperation   Type of file operation
fileno          File identification number
filetype        Type of file (for example, log file, data file, and so on)

SCOTT@book> set verify off
SCOTT@book> @ ev_name "Disk file operations I/O"
EVENT#   EVENT_ID NAME                     PARAMETER1    PARAMETER2 PARAMETER3 WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS
------ ---------- ------------------------ ------------- ---------- ---------- ------------- ----------- ----------
    11  166678035 Disk file operations I/O FileOperation fileno     filetype      1740759767           8 User I/O

So mainly FileOperation type 2 and filetype 2.
What are the file types? Not sure, but thanks to Andy Klock on Oracle-L  this looks like a possibility:

SCOTT@book> select distinct filetype_id, filetype_name from DBA_HIST_IOSTAT_FILETYPE order by 1;
FILETYPE_ID FILETYPE_NAME
----------- ------------------------------
          0 Other
          1 Control File
          2 Data File
          3 Log File
          4 Archive Log
          6 Temp File
          9 Data File Backup
         10 Data File Incremental Backup
         11 Archive Log Backup
         12 Data File Copy
         17 Flashback Log
         18 Data Pump Dump File
12 rows selected.
--//补充:上面不是很全，我记忆里13是spfile，没有列出。

What about FileOperation=2? After a call to Oracle support, it looks like on this version, 11.2.0.3 the values are:

    1 file creation
    2 file open
    3 file resize
    4 file deletion
    5 file close
    6 wait for all aio requests to finish
    7 write verification
    8 wait for miscellaneous io (ftp, block dump, passwd file)
    9 read from snapshot files

3.分析一：
--//正如上面介绍的此事件用于等待磁盘文件操作(例如，打开、关闭、查找和调整大小)。 它还用于各种I/O操作，如块转储和密码文件
--//访问。可以看出主要应该出现在读取打开关闭寻道调整大小事时各种oracle相关文件出现这个等待事件。

--//可以看出对应文件型数据库最多应该出现在控制文件，参数文件以及其它相关oracle文件，而出现在数据文件的可能性相对较小，因为
--//数据块会进入缓存，这样用户进程访问该块并不需要打开对应数据文件句柄。而且对应进程一旦打开文件句柄不会关闭，除非退出。
--//下面我通过测试说明我对这个问题的理解：

--//session 1:
SCOTT@book(30,1893)> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        30       1893 2186                     DEDICATED 2187        26        104 alter system kill session '30,1893' immediate;
--//进程号2187,sid=30

--//session 2:
SYS@book(44,2183)> select * from v$session_wait_history where sid=30 and event='Disk file operations I/O';
no rows selected
--//没有出现Disk file operations I/O等待事件。注意使用v$session_wait_history分析相对简单一些。

--//session 1:
SCOTT@book(30,1893)> SELECT value c20  FROM v$spparameter WHERE name = 'standby_file_management' AND sid='*';
C20
--------------------
auto

--//session 2:
SYS@book(44,2183)> select * from v$session_wait_history where sid=30 and event='Disk file operations I/O';
SID SEQ# EVENT# EVENT                    P1TEXT        P1 P2TEXT   P2 P3TEXT     P3  WAIT_TIME WAIT_TIME_MICRO TIME_SINCE_LAST_WAIT_MICRO
--- ---- ------ ------------------------ ------------- -- -------- -- --------- --- ---------- --------------- --------------------------
 30    3     11 Disk file operations I/O FileOperation  5 fileno    0 filetype   13          0              11                          8
 30    6     11 Disk file operations I/O FileOperation  2 fileno    0 filetype   13          0             450                         50
--//出现Disk file operations I/O等待事件。注意P1=5按照上面介绍对应file close。P1=2对应file open。
--//而P3=13 很明显是spfile文件。

--//使用strace跟踪，重复执行看看：
$ strace -f -p 2187 -e open,close,pread,fcntl
Process 2187 attached - interrupt to quit
open("/u01/app/oracle/product/11.2.0.4/dbhome_1/dbs", O_RDONLY) = 8
close(8)                                = 0
open("/etc/mtab", O_RDONLY)             = 8
close(8)                                = 0
open("/etc/mtab", O_RDONLY)             = 8
close(8)                                = 0
open("/etc/mtab", O_RDONLY)             = 8
close(8)                                = 0
open("/u01/app/oracle/product/11.2.0.4/dbhome_1/dbs/spfilebook.ora", O_RDONLY) = 8
close(8)                                = 0
open("/u01/app/oracle/product/11.2.0.4/dbhome_1/dbs/spfilebook.ora", O_RDONLY) = 8
close(8)                                = 0
open("/u01/app/oracle/product/11.2.0.4/dbhome_1/dbs/spfilebook.ora", O_RDWR|O_SYNC) = 8
fcntl(8, F_DUPFD, 256)                  = 259
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
close(8)                                = 0
fcntl(259, F_SETFD, FD_CLOEXEC)         = 0
fcntl(259, F_GETFL)                     = 0x9002 (flags O_RDWR|O_SYNC|O_LARGEFILE)
fcntl(259, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
pread(259, "C\"\0\0\1\0\0\0\0\0\0\0\0\0\1\4vJ\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512, 0) = 512
pread(259, "C\"\0\0\2\0\0\0\0\0\0\0\0\0\1\4qi\0\0book.__db_ca"..., 2560, 512) = 2560
fcntl(259, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
close(259)                              = 0
open("/u01/app/oracle/product/11.2.0.4/dbhome_1/oracore/mesg/lrmus.msb", O_RDONLY) = 8
fcntl(8, F_SETFD, FD_CLOEXEC)           = 0
close(8)                                = 0

--//你可以看到打开3次参数文件，有点奇怪的读的文件句柄是259，如果你注意下划线fcntl函数将它定向到文件句柄259，然后close(8).
--//仔细看strace跟踪还可以发现open，close出现多次。
--//做一次10046跟踪看看：
SCOTT@book(30,1893)> @ 10046on 12
Session altered.

SCOTT@book(30,1893)> SELECT value c20  FROM v$spparameter WHERE name = 'standby_file_management' AND sid='*';
C20
--------------------
auto

SCOTT@book(30,1893)> @ 10046off
Session altered.

$ grep "Disk file operations I/O" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trc
WAIT #139793450719904: nam='Disk file operations I/O' ela= 294 FileOperation=2 fileno=0 filetype=13 obj#=547 tim=1616721166803246
WAIT #139793450719904: nam='Disk file operations I/O' ela= 10 FileOperation=5 fileno=0 filetype=13 obj#=547 tim=1616721166803366
--//仅仅出现2次。obj#=547表示什么。

SYS@book(44,2183)> select * from dba_objects where object_id=547 or data_object_id=547
  2  @ prxx
==============================
OWNER                         : SYS
OBJECT_NAME                   : KOTTB$
SUBOBJECT_NAME                :
OBJECT_ID                     : 547
DATA_OBJECT_ID                : 547
OBJECT_TYPE                   : TABLE
CREATED                       : 2013-08-24 11:37:43
LAST_DDL_TIME                 : 2013-08-24 11:37:43
TIMESTAMP                     : 2013-08-24:11:37:43
STATUS                        : VALID
TEMPORARY                     : N
GENERATED                     : N
SECONDARY                     : N
NAMESPACE                     : 1
EDITION_NAME                  :
PL/SQL procedure successfully completed.

--//这个表KOTTB$很奇特，我估计用来加载参数文件信息的。
SYS@book(44,2183)> select * from KOTTB$;
select * from KOTTB$
              *
ERROR at line 1:
ORA-30732: table contains no user-visible columns

SYS@book(44,2183)> @ ddl sys.KOTTB$;
C100
----------------------------------------------------------------------------------------------------
  CREATE TABLE "SYS"."KOTTB$" OF "SYS"."KOTTB"
 OIDINDEX  ( PCTFREE 10 INITRANS 2 MAXTRANS 255
  STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
  BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
  TABLESPACE "SYSTEM" )
 PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
 NOCOMPRESS LOGGING
  STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
  BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
  TABLESPACE "SYSTEM" ;

--//可以发现执行类似的语句读参数文件,出现Disk file operations IO应该是正常的，一点不奇怪。因为每次都重复open,pread,close。
--//并且参数文件信息并不会进入数据缓存，每次执行都要重新读取参数文件。
--//所以将对于文件性数据库，读取参数文件每次都出现Disk file operations IO是正常的情况。

3.分析二：
--//控制文件呢？控制文件有一点点不同，看看下面我的分析：
--//session 3:
SCOTT@book(58,2019)> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        58       2019 2411                     DEDICATED 2412        28         50 alter system kill session '58,2019' immediate;

$ ls -l /proc/2412/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 10 -> pipe:[3628263]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 2 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 5 -> /proc/2412/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 7 -> pipe:[3628262]
--//并没有打开控制文件的句柄。

SCOTT@book(58,2019)> @ 10046on 12
Session altered.

SCOTT@book(58,2019)> select * from v$database;
--//注：这条语句许多信息来源于控制文件。也就是要访问控制文件。

SCOTT@book(58,2019)> @ 10046off
Session altered.

$ ls -l /proc/2412/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 10 -> pipe:[3628263]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 09:31:40 256 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 09:31:40 257 -> /mnt/ramdisk/book/control02.ctl
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 5 -> /proc/2412/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 7 -> pipe:[3628262]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:31:40 8 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trc
l-wx------ 1 oracle oinstall 64 2021-03-26 09:31:40 9 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trm
--//你可以发现执行完后打开了控制文件的句柄256，257.

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trc
WAIT #139739009568744: nam='Disk file operations I/O' ela= 80 FileOperation=2 fileno=0 filetype=1 obj#=-1 tim=1616722218802285
WAIT #139739009568744: nam='Disk file operations I/O' ela= 16 FileOperation=2 fileno=1 filetype=1 obj#=-1 tim=1616722218802333
--//filetype=1  对应的就是control file。你还可以注意一个小小的细节，就是没有close(FileOperation=5)。
--//这点可以从上面的ls -l /proc/2412/fd显示可以确定，控制文件的句柄没有关闭。
--//这样如果该会话再次访问控制文件，就不再会出现Disk file operations I/O等待事件了。

SCOTT@book(58,2019)> @ 10046on 12
Session altered.

SCOTT@book(58,2019)> select * from v$database;

SCOTT@book(58,2019)> @ 10046off
Session altered.

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trc
WAIT #139739009568744: nam='Disk file operations I/O' ela= 80 FileOperation=2 fileno=0 filetype=1 obj#=-1 tim=1616722218802285
WAIT #139739009568744: nam='Disk file operations I/O' ela= 16 FileOperation=2 fileno=1 filetype=1 obj#=-1 tim=1616722218802333
--//依旧仅仅看到2条。
--//补充还有一点点细节，第2行出现fileno=1,而前面的ls -l /proc/2412/fd 并没有显示打开system数据文件，也就是oracle把P2解析
--//为File identification number,我估计在这里指第2个控制文件(/mnt/ramdisk/book/control02.ctl)。

4.分析三：
--//访问数据库里面的数据块呢？情况有有所不同，oracle有数据缓存,有可能你访问的数据块已经在数据缓存了。
--//这样在访问时不需要打开对应数据文件的文件句柄就可以通过数据缓存读取到该块，也就是这样不会出现
--//Disk file operations I/O。
--//还有一种可能就是该进程下对应数据文件的句柄已经打开了，这样即使数据块不在缓存，也不会出现Disk file operations I/O。
--//session 3:
SCOTT@book(58,2019)> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        58       2019 2411                     DEDICATED 2412        28         50 alter system kill session '58,2019' immediate;

$  ls -l /proc/2412/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 10 -> pipe:[3628263]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 09:31:40 256 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 09:31:40 257 -> /mnt/ramdisk/book/control02.ctl
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 5 -> /proc/2412/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 7 -> pipe:[3628262]

--//session 2：
SYS@book(44,2183)> alter system flush buffer_cache;
System altered.

--//session 1:
SCOTT@book(58,2019)> @ 10046on 12
Session altered.

SCOTT@book(58,2019)> select * from dept where rownum=1;
    DEPTNO DNAME          LOC
---------- -------------- -------------
        10 ACCOUNTING     NEW YORK

SCOTT@book(58,2019)> @ 10046off
Session altered.

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trc
WAIT #139739009568744: nam='Disk file operations I/O' ela= 80 FileOperation=2 fileno=0 filetype=1 obj#=-1 tim=1616722218802285
WAIT #139739009568744: nam='Disk file operations I/O' ela= 16 FileOperation=2 fileno=1 filetype=1 obj#=-1 tim=1616722218802333
WAIT #139739010661336: nam='Disk file operations I/O' ela= 42 FileOperation=2 fileno=1 filetype=2 obj#=37 tim=1616723599517954
WAIT #139739010956368: nam='Disk file operations I/O' ela= 28 FileOperation=2 fileno=4 filetype=2 obj#=87106 tim=1616723599571393

--//注：我没有删除前面看到的2行。可以发现出现2次。
--//filetype=2 对应Data File，这样fileno=1,4对应文件号。
SYS@book(44,2183)> select * from v$dbfile where file# in (1,4);
     FILE# NAME
---------- ----------------------------------------
         4 /mnt/ramdisk/book/users01.dbf
         1 /mnt/ramdisk/book/system01.dbf

$  ls -l /proc/2412/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 10 -> pipe:[3628263]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:29:23 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 09:31:40 256 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 09:31:40 257 -> /mnt/ramdisk/book/control02.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 09:57:38 258 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 09:57:38 259 -> /mnt/ramdisk/book/users01.dbf
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 5 -> /proc/2412/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 09:29:23 7 -> pipe:[3628262]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:31:40 8 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trc
l-wx------ 1 oracle oinstall 64 2021-03-26 09:31:40 9 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2412.trm

--//可以发现对应进程下多打开了/mnt/ramdisk/book/system01.dbf，/mnt/ramdisk/book/users01.dbf。
--//如果这个时候其它会话访问dept表块，因为该块已经在数据缓存里面了，也不用打开对应文件句柄访问该块，这样不会出现Disk
--//file operations I/O。

--//session 1:
SCOTT@book(30,1893)> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        30       1893 2186                     DEDICATED 2187        26        104 alter system kill session '30,1893' immediate;

$ ll /proc/2187/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 10 -> pipe:[3628207]
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 08:56:58 256 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 08:58:14 257 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 08:58:14 258 -> /mnt/ramdisk/book/control02.ctl
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 5 -> /proc/2187/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 7 -> pipe:[3628206]
--//没有打开/mnt/ramdisk/book/users01.dbf。

--//session 1:
SCOTT@book(30,1893)> @ 10046on 12
Session altered.

SCOTT@book(30,1893)> select * from dept where rownum=1;
    DEPTNO DNAME          LOC
---------- -------------- -------------
        10 ACCOUNTING     NEW YORK

SCOTT@book(30,1893)> @ 10046off
Session altered.

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trc
WAIT #139793450719904: nam='Disk file operations I/O' ela= 294 FileOperation=2 fileno=0 filetype=13 obj#=547 tim=1616721166803246
WAIT #139793450719904: nam='Disk file operations I/O' ela= 10 FileOperation=5 fileno=0 filetype=13 obj#=547 tim=1616721166803366
--//注我没有删除前面看到的2行，从filetype=13可以看出没有出现Disk file operations I/O。

$ ll /proc/2187/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 10 -> pipe:[3628207]
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 08:56:58 256 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 08:58:14 257 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 08:58:14 258 -> /mnt/ramdisk/book/control02.ctl
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 5 -> /proc/2187/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 7 -> pipe:[3628206]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:47:39 8 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trc
l-wx------ 1 oracle oinstall 64 2021-03-26 09:47:39 9 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trm
--//没有打开/mnt/ramdisk/book/users01.dbf文件句柄。
--//如果你刷新数据缓存呢？
--//session 2:
SYS@book(44,2183)> alter system flush buffer_cache;
System altered.
--//注最好选择其它会话刷新数据缓存，避免意外打开对应的文件句柄。

--//session 1:
SCOTT@book(30,1893)> @ 10046on 12
Session altered.

SCOTT@book(30,1893)> select * from dept where rownum=1;
    DEPTNO DNAME          LOC
---------- -------------- -------------
        10 ACCOUNTING     NEW YORK

SCOTT@book(30,1893)> @ 10046off
Session altered.

$ ls -l /proc/2187/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 10 -> pipe:[3628207]
l-wx------ 1 oracle oinstall 64 2021-03-26 08:56:58 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 08:56:58 256 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 08:58:14 257 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 08:58:14 258 -> /mnt/ramdisk/book/control02.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 10:08:45 259 -> /mnt/ramdisk/book/users01.dbf
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 5 -> /proc/2187/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 08:56:58 7 -> pipe:[3628206]
l-wx------ 1 oracle oinstall 64 2021-03-26 09:47:39 8 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trc
l-wx------ 1 oracle oinstall 64 2021-03-26 09:47:39 9 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trm
--//打开/mnt/ramdisk/book/users01.dbf文件句柄。

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trc
WAIT #139793450719904: nam='Disk file operations I/O' ela= 294 FileOperation=2 fileno=0 filetype=13 obj#=547 tim=1616721166803246
WAIT #139793450719904: nam='Disk file operations I/O' ela= 10 FileOperation=5 fileno=0 filetype=13 obj#=547 tim=1616721166803366
WAIT #139793449072216: nam='Disk file operations I/O' ela= 46 FileOperation=2 fileno=4 filetype=2 obj#=87106 tim=1616724500940194
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
--//出现了Disk file operations I/O.FileOperation=2 fileno=4 filetype=2.

--//如果再次刷新，session 1再次重复测试，因为对应文件句柄已经打开，应该也不会出现Disk file operations I/O。
--//session 2:
SYS@book(44,2183)> alter system flush buffer_cache;
System altered.

--//session 1:
SCOTT@book(30,1893)> @ 10046on 12
Session altered.

SCOTT@book(30,1893)> select * from dept where rownum=1;
    DEPTNO DNAME          LOC
---------- -------------- -------------
        10 ACCOUNTING     NEW YORK

SCOTT@book(30,1893)> @ 10046off
Session altered.

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2187.trc
WAIT #139793450719904: nam='Disk file operations I/O' ela= 294 FileOperation=2 fileno=0 filetype=13 obj#=547 tim=1616721166803246
WAIT #139793450719904: nam='Disk file operations I/O' ela= 10 FileOperation=5 fileno=0 filetype=13 obj#=547 tim=1616721166803366
WAIT #139793449072216: nam='Disk file operations I/O' ela= 46 FileOperation=2 fileno=4 filetype=2 obj#=87106 tim=1616724500940194
--//依旧是3行。没有再次出现Disk file operations I/O。

--//可以看出对于数据块是否出现Disk file operations I/O，主要有几种情况需要考虑：
--//数据块是否缓存，相应进程是否打开对应的文件句柄。另外注意一点一旦打开不会关闭对应的文件句柄，除非退出。

5.分析四：
--//如果执行计划直接路径读呢？测试参考链接http://blog.itpub.net/267265/viewspace-2143334/。
--//直接路径读绕过了数据缓存，直接读取数据块进入PGA，通过上面的特例测试。
--//session 3:
SCOTT@book(58,2019)> select rowid,dept.* from dept ;
ROWID                  DEPTNO DNAME          LOC
------------------ ---------- -------------- -------------
AAAVRCAAEAAAACHAAA         10 ACCOUNTING     NEW YORK
AAAVRCAAEAAAACHAAB         20 RESEARCH       DALLAS
AAAVRCAAEAAAACHAAC         30 SALES          CHICAGO
AAAVRCAAEAAAACHAAD         40 OPERATIONS     BOSTON

--//session 2:
SYS@book(44,2183)> alter system flush buffer_cache;
System altered.

--//session 3:
SCOTT@book(58,2019)> select rowid,dept.* from dept where rowid='AAAVRCAAEAAAACHAAA';
ROWID                  DEPTNO DNAME          LOC
------------------ ---------- -------------- -------------
AAAVRCAAEAAAACHAAA         10 ACCOUNTING     NEW YORK

--//session 2:
SYS@book(44,2183)> @ rowid AAAVRCAAEAAAACHAAA
    OBJECT       FILE      BLOCK        ROW ROWID_DBA            DBA                  TEXT
---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------
     87106          4        135          0  0x1000087           4,135                alter system dump datafile 4 block 135 ;

SYS@book(44,2183)> @ bh 4 135
   INST_ID HLADDR              DBARFIL     DBABLK      CLASS CLASS_TYPE         STATE             TCH CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ BA               LE_ADDR          OBJECT_NAME
---------- ---------------- ---------- ---------- ---------- ------------------ ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------------- ---------------- --------------------
         1 0000000084D25320          4        135          1 data block         xcur                1          0          0          0          0          0 00000000654FC000 00               DEPT
--//这样该块进入数据缓存。不放心可以执行多次。

--//session 3:
SCOTT@book(58,2019)> alter session set statistics_level=all;
Session altered.

select * from dept where rowid between 'AAAVRCAAEAAAACHAAA' and 'AAAVRCAAEAAAACHAAB';
--//注执行多次查看执行计划可以发现存在物理读。我这里不测试了。

--//session 4:
SCOTT@book(72,1179)> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        72       1179 2796                     DEDICATED 2797        29          6 alter system kill session '72,1179' immediate;

$ ll /proc/2797/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 10:40:40 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 10:40:40 10 -> pipe:[3628369]
l-wx------ 1 oracle oinstall 64 2021-03-26 10:40:40 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 10:40:40 256 -> /mnt/ramdisk/book/system01.dbf
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 5 -> /proc/2797/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 7 -> pipe:[3628368]
--//没有打开/mnt/ramdisk/book/user01.dbf文件句柄。

SCOTT@book(72,1179)> @ 10046on 12
Session altered.

select * from dept where rowid between 'AAAVRCAAEAAAACHAAA' and 'AAAVRCAAEAAAACHAAB';
select * from dept where rowid between 'AAAVRCAAEAAAACHAAA' and 'AAAVRCAAEAAAACHAAB';
        
SCOTT@book(72,1179)> @ 10046off
Session altered.

$ ll /proc/2797/fd
total 0
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 0 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 10:40:40 1 -> /dev/null
l-wx------ 1 oracle oinstall 64 2021-03-26 10:40:40 10 -> pipe:[3628369]
l-wx------ 1 oracle oinstall 64 2021-03-26 10:40:40 2 -> /dev/null
lrwx------ 1 oracle oinstall 64 2021-03-26 10:40:40 256 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:41:46 257 -> /mnt/ramdisk/book/users01.dbf
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 3 -> /dev/null
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 4 -> /u01/app/oracle/product/11.2.0.4/dbhome_1/rdbms/mesg/oraus.msb
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 5 -> /proc/2797/fd
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 6 -> /dev/zero
lr-x------ 1 oracle oinstall 64 2021-03-26 10:40:40 7 -> pipe:[3628368]
l-wx------ 1 oracle oinstall 64 2021-03-26 10:41:46 8 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2797.trc
l-wx------ 1 oracle oinstall 64 2021-03-26 10:41:46 9 -> /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2797.trm
--//打开/mnt/ramdisk/book/user01.dbf文件句柄。

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2797.trc
WAIT #139753629750824: nam='Disk file operations I/O' ela= 38 FileOperation=2 fileno=4 filetype=2 obj#=87106 tim=1616726471319299
--//出现了Disk file operations I/O.注意仅仅出现1次。
--//也就是一旦打开对应文句柄就不会出现Disk file operations I/O。

6.总结：
--//不小心又写的很长。
--//对于文件型数据库，如果语句涉及读取参数文件，一定会遇到Disk file operations I/O。
--//而像控制文件如果会话第一次执行访问控制文件的语句，一定会遇到Disk file operations I/O，以后就不会出现。
--//可以看出对于数据块是否出现Disk file operations I/O，主要有几种情况需要考虑：
--//数据块是否缓存，相应进程是否打开对应的文件句柄。另外注意一点一旦打开不会关闭对应的文件句柄，除非退出。
--//直接路径读情况有一点点特殊，即使在有数据缓存，一定相应进程打开对应的文件句柄才不会出现Disk file operations I/O。
--//仔细想想我的测试直接路径读还是有1点点瑕疵，因为那个特性利用段头不在数据缓存的情况下才能测出。
--//而且访问段头就需要打开相应数据文件。

7.补充一些无法解析的情况：
--//session 2:
SYS@book(44,2183)> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        44       2183 2189                     DEDICATED 2190        27        104 alter system kill session '44,2183' immediate;

$ ll /proc/2190/fd | egrep "dbf|ctl"
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 256 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 257 -> /mnt/ramdisk/book/temp01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 258 -> /mnt/ramdisk/book/sysaux01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 259 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 260 -> /mnt/ramdisk/book/control02.ctl
--//没有打开/mnt/ramdisk/book/users01.dbf

--//session 1:
--//产生一些脏块。
SCOTT@book(30,1893)> update empx set ename=lower(ename);
14 rows updated.

SCOTT@book(30,1893)> commit ;
Commit complete.

--//session 2:
SYS@book(44,2183)> @ 10046on 12
Session altered.

SYS@book(44,2183)> alter system flush buffer_cache;
System altered.

SYS@book(44,2183)> @ 10046off
Session altered.

$ grep 'Disk file operations I/O'  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_2190.trc
WAIT #140012911193480: nam='Disk file operations I/O' ela= 50 FileOperation=8 fileno=0 filetype=8 obj#=18 tim=1616727922986804
WAIT #140012911194728: nam='Disk file operations I/O' ela= 76 FileOperation=8 fileno=0 filetype=8 obj#=18 tim=1616727925479330
--//不理解FileOperation=8 fileno=0 filetype=8
$ strace -f -p 2190 -e open,close,pread,fcntl
Process 2190 attached - interrupt to quit
open("/u01/app/oracle/diag/rdbms/book/book/alert/log.xml", O_WRONLY|O_CREAT|O_APPEND, 0660) = 14
fcntl(14, F_SETFD, FD_CLOEXEC)          = 0
close(14)                               = 0
open("/u01/app/oracle/diag/rdbms/book/book/trace/alert_book.log", O_WRONLY|O_CREAT|O_APPEND, 0660) = 14
fcntl(14, F_SETFD, FD_CLOEXEC)          = 0
close(14)                               = 0
^CProcess 2190 detached
--//视乎是指aler文件。

SCOTT@book(30,1893)> select * from dba_objects where object_id=18
  2  @ prxx
==============================
OWNER                         : SYS
OBJECT_NAME                   : OBJ$
SUBOBJECT_NAME                :
OBJECT_ID                     : 18
DATA_OBJECT_ID                : 18
OBJECT_TYPE                   : TABLE
CREATED                       : 2013-08-24 11:37:35
LAST_DDL_TIME                 : 2013-08-24 11:59:25
TIMESTAMP                     : 2013-08-24:11:37:35
STATUS                        : VALID
TEMPORARY                     : N
GENERATED                     : N
SECONDARY                     : N
NAMESPACE                     : 1
EDITION_NAME                  :
PL/SQL procedure successfully completed.

$ ll /proc/2190/fd | egrep "dbf|ctl"
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 256 -> /mnt/ramdisk/book/system01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 257 -> /mnt/ramdisk/book/temp01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 258 -> /mnt/ramdisk/book/sysaux01.dbf
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 259 -> /mnt/ramdisk/book/control01.ctl
lrwx------ 1 oracle oinstall 64 2021-03-26 10:06:54 260 -> /mnt/ramdisk/book/control02.ctl

8.贴一个生产系统的情况：
> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.3.0     Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production

> @ ashtop sql_id,p1,p2,p3,session_id "MACHINE<>'IMC' and event='Disk file operations I/O'"  trunc(sysdate)-100 trunc(sysdate)+1
  Total
Seconds     AAS %This   SQL_ID         P1  P2  P3 SESSION_ID FIRST_SEEN          LAST_SEEN
------- ------- ------- ------------- --- --- --- ---------- ------------------- -------------------
      8      .0   15% | ctf9dvtv2qua0   2   0  13       1249 2021-03-23 21:59:12 2021-03-26 10:29:13
      7      .0   13% | dnk8dw55sjz3h   2   0  13       1249 2021-03-23 16:48:07 2021-03-26 01:20:03
      6      .0   11% | 633r6yjw2810x   2   0  13       1249 2021-03-23 15:59:06 2021-03-26 10:16:12
      5      .0    9% | 2tp6sujs7jxhp   2   0  13       1249 2021-03-24 11:26:25 2021-03-26 12:31:15
      5      .0    9% |                 4   0   9         19 2021-03-25 01:22:24 2021-03-25 01:22:34
      4      .0    7% | 2xaxq1vhryghu   2   0  13       1249 2021-03-23 13:15:03 2021-03-26 04:43:07
      3      .0    5% | 9wj2g5x2ggpya   2   0  13       1249 2021-03-24 20:07:34 2021-03-25 06:11:44
      3      .0    5% | cr7mmwh94tz9a   2   0  13       1249 2021-03-24 00:00:14 2021-03-26 05:11:07
      3      .0    5% |                 4   0   4         19 2021-03-25 01:22:32 2021-03-25 01:22:37
      2      .0    4% |                 1   1   9        428 2021-03-25 01:11:06 2021-03-25 01:22:16
      2      .0    4% |                 1   1   9        855 2021-03-25 01:13:15 2021-03-25 01:13:18
      1      .0    2% | 4nw903nu8qxkc   2   3   2        444 2021-03-25 08:25:15 2021-03-25 08:25:15
      1      .0    2% | 4pcnjr43r5rt2   2   0  13       1249 2021-03-23 14:47:05 2021-03-23 14:47:05
      1      .0    2% | 7mgr3uwydqq8j   2   0   1         34 2021-03-25 05:51:26 2021-03-25 05:51:26
      1      .0    2% |                 1   0   4        834 2021-03-26 08:22:58 2021-03-26 08:22:58
      1      .0    2% |                 1   0   4       1251 2021-03-25 10:53:03 2021-03-25 10:53:03
      1      .0    2% |                 2   0   3       1252 2021-03-26 09:42:06 2021-03-26 09:42:06
      1      .0    2% |                 2   7   2        430 2021-03-25 22:12:19 2021-03-25 22:12:19
18 rows selected.
--//注意看基本都是session_id=124执行的。p3=13值参数文件。其它基本很少出现。

> @ sqlid ctf9dvtv2qua0
SQL_ID        SQLTEXT
------------- ------------------------------------------------------------------------------------
ctf9dvtv2qua0 SELECT value FROM v$spparameter WHERE name = 'log_file_name_convert' and ordinal = 1
--//查看的正是参数文件。

> @ sid 1249
sid = 1249
SPID   PID  SID    SERIAL# CLIENT_INFO PNAME  TRACEFILE                                                           PROGRAM                TERMINAL     SQL_ID STATUS   C50
------ --- ---- ---------- ----------- ------ ------------------------------------------------------------------- ---------------------- ------------ ------ -------- --------------------------------------------------
3650    23 1249          1             RSM0   /u01/app/oracle/diag/rdbms/hrp430/hrp430/trace/hrp430_rsm0_3650.trc oracle@xhserver (RSM0) UNKNOWN             ACTIVE   alter system kill session '1249,1' immediate;

SYS@192.168.31.8:1521/hrp430> @ bg rsm
ADDR                 PID SPID   PROGRAM
---------------- ------- ------ ----------------------------------------
00000000BD7A83A0      23 3650   oracle@xhserver (RSM0)
--//都是后台进程RSM0(broker resource manager)，这个进程是运行dg broken相关的进程。