Skip to Main Content

Oracle Database Discussions

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

Interested in getting your voice heard by members of the Developer Marketing team at Oracle? Check out this post for AppDev or this post for AI focus group information.

wrong 'physical read total multi block requests' ?

Franck PachotJan 23 2015 — edited Jan 23 2015

Hi,

The statistic 'physical read total multi block requests' is expected to count the number of i/o calls reading more than one block (doc here). Thus I expect it to be equal to the 'db file scattered read' (or 'direct path read' if serial direct-path read is used).

But That's not what I get in the following testcase:

SQL> create table DEMO pctfree 99 as select rpad('x',1000,'x') n from dual connect by level <=1000;

-- I get v$filestat statistics in order to do the difference at the end:

SQL> select phyrds,phyblkrd,singleblkrds from v$filestat where file#=6;

    PHYRDS   PHYBLKRD SINGLEBLKRDS

---------- ---------- ------------

      6291      96488         3286

I do a full table scan on a 1000 blocks table, forcing buffered reads and sql_tracing

SQL> connect demo/demo

Connected.

SQL> alter session set "_serial_direct_read"=never;

Session altered.

SQL> alter session set events='sql_trace wait=true';

Session altered.

SQL> select count(*) from DEMO;

  COUNT(*)

----------

      1000

SQL> alter session set events='sql_trace off';

session statistics show 30 IO requests but only 14 multi block requests:

SQL> select name,value from v$mystat join v$statname using(statistic#) where name like 'phy%' and value>0;

NAME                                          VALUE

---------------------------------------- ----------

physical read total IO requests                  30

physical read total multi block requests         14

physical read total bytes                   8192000

physical reads                                 1000

physical reads cache                           1000

physical read IO requests                        30

physical read bytes                         8192000

physical reads cache prefetch                   970

However I did 30 'db file squattered read':

SQL> select event,total_waits from v$session_event where sid=sys_context('userenv','sid');

EVENT                                    TOTAL_WAITS

---------------------------------------- -----------

Disk file operations I/O                           1

log file sync                                      1

db file scattered read                            30

SQL*Net message to client                         20

SQL*Net message from client                       19

V$FILESTAT counts them as multiblock reads as well:

SQL> select phyrds-      6291 phyrds,phyblkrd-     96488 phyblkrd,singleblkrds-      3286 singleblkrds from v$filestat where file#=6

    PHYRDS   PHYBLKRD SINGLEBLKRDS

---------- ---------- ------------

        30       1000            0

And that's confirmed by sql_trace

SQL> column tracefile new_value tracefile

SQL> select tracefile from v$process where addr=(select paddr from v$session where sid=sys_context('USERENV','SID'));

TRACEFILE

------------------------------------------------------------------------

/u01/app/oracle/diag/rdbms/dbvs103/DBVS103/trace/DBVS103_ora_31822.trc

SQL> host mv &tracefile serial-direct-path.trc

SQL> host grep ^WAIT serial-direct-path.trc | grep read | nl

     1  WAIT #139711696129328: nam='db file scattered read' ela= 456 file#=6 block#=5723 blocks=5 obj#=95361 tim=48370540177

     2  WAIT #139711696129328: nam='db file scattered read' ela= 397 file#=6 block#=5728 blocks=8 obj#=95361 tim=48370542452

     3  WAIT #139711696129328: nam='db file scattered read' ela= 449 file#=6 block#=5737 blocks=7 obj#=95361 tim=48370543216

     4  WAIT #139711696129328: nam='db file scattered read' ela= 472 file#=6 block#=5744 blocks=8 obj#=95361 tim=48370543816

     5  WAIT #139711696129328: nam='db file scattered read' ela= 334 file#=6 block#=5753 blocks=7 obj#=95361 tim=48370544276

     6  WAIT #139711696129328: nam='db file scattered read' ela= 425 file#=6 block#=5888 blocks=8 obj#=95361 tim=48370544848

     7  WAIT #139711696129328: nam='db file scattered read' ela= 304 file#=6 block#=5897 blocks=7 obj#=95361 tim=48370545370

     8  WAIT #139711696129328: nam='db file scattered read' ela= 599 file#=6 block#=5904 blocks=8 obj#=95361 tim=48370546190

     9  WAIT #139711696129328: nam='db file scattered read' ela= 361 file#=6 block#=5913 blocks=7 obj#=95361 tim=48370546682

    10  WAIT #139711696129328: nam='db file scattered read' ela= 407 file#=6 block#=5920 blocks=8 obj#=95361 tim=48370547224

    11  WAIT #139711696129328: nam='db file scattered read' ela= 359 file#=6 block#=5929 blocks=7 obj#=95361 tim=48370547697

    12  WAIT #139711696129328: nam='db file scattered read' ela= 381 file#=6 block#=5936 blocks=8 obj#=95361 tim=48370548287

    13  WAIT #139711696129328: nam='db file scattered read' ela= 362 file#=6 block#=6345 blocks=7 obj#=95361 tim=48370548762

    14  WAIT #139711696129328: nam='db file scattered read' ela= 355 file#=6 block#=6352 blocks=8 obj#=95361 tim=48370549218

    15  WAIT #139711696129328: nam='db file scattered read' ela= 439 file#=6 block#=6361 blocks=7 obj#=95361 tim=48370549765

    16  WAIT #139711696129328: nam='db file scattered read' ela= 370 file#=6 block#=6368 blocks=8 obj#=95361 tim=48370550276

    17  WAIT #139711696129328: nam='db file scattered read' ela= 1379 file#=6 block#=7170 blocks=66 obj#=95361 tim=48370552358

    18  WAIT #139711696129328: nam='db file scattered read' ela= 1205 file#=6 block#=7236 blocks=60 obj#=95361 tim=48370554221

    19  WAIT #139711696129328: nam='db file scattered read' ela= 1356 file#=6 block#=7298 blocks=66 obj#=95361 tim=48370556081

    20  WAIT #139711696129328: nam='db file scattered read' ela= 1385 file#=6 block#=7364 blocks=60 obj#=95361 tim=48370557969

    21  WAIT #139711696129328: nam='db file scattered read' ela= 832 file#=6 block#=7426 blocks=66 obj#=95361 tim=48370560016

    22  WAIT #139711696129328: nam='db file scattered read' ela= 1310 file#=6 block#=7492 blocks=60 obj#=95361 tim=48370563004

    23  WAIT #139711696129328: nam='db file scattered read' ela= 1315 file#=6 block#=9602 blocks=66 obj#=95361 tim=48370564728

    24  WAIT #139711696129328: nam='db file scattered read' ela= 420 file#=6 block#=9668 blocks=60 obj#=95361 tim=48370565786

    25  WAIT #139711696129328: nam='db file scattered read' ela= 1218 file#=6 block#=9730 blocks=66 obj#=95361 tim=48370568282

    26  WAIT #139711696129328: nam='db file scattered read' ela= 1041 file#=6 block#=9796 blocks=60 obj#=95361 tim=48370569809

    27  WAIT #139711696129328: nam='db file scattered read' ela= 300 file#=6 block#=9858 blocks=66 obj#=95361 tim=48370570501

    28  WAIT #139711696129328: nam='db file scattered read' ela= 281 file#=6 block#=9924 blocks=60 obj#=95361 tim=48370571248

    29  WAIT #139711696129328: nam='db file scattered read' ela= 305 file#=6 block#=9986 blocks=66 obj#=95361 tim=48370572021

    30  WAIT #139711696129328: nam='db file scattered read' ela= 347 file#=6 block#=10052 blocks=60 obj#=95361 tim=48370573387

So, I'm sure that I 've done 30 multiblock reads but physical read total multi block requests = 14

Any idea why?

Thanks in advance,

Franck.

This post has been answered by Jonathan Lewis on Jan 23 2015
Jump to Answer

Comments

Processing
Locked Post
New comments cannot be posted to this locked post.

Post Details

Locked on Feb 20 2015
Added on Jan 23 2015
8 comments
2,575 views