LOGICAL_READS_PER_SESSION

One of the resources you can limit in a profile is called logical_reads_per_session. According to the Oracle documentation, it is used to:

Specify the permitted number of data blocks read in a session, including blocks read from memory and disk. I decided to try it out in an Oracle 11.1 database.

 

I created a profile called for_andrew, which would limit logical_reads_per_session to 10000:

SQL> conn / as sysdba

Connected.

SQL> create profile for_andrew

  2  limit logical_reads_per_session 10000

  3  /

 

Profile created.

 

SQL>

I set resource_limit to true so that Oracle would enforce the logical_reads_per_session limit:

SQL> alter system set resource_limit = true

  2  /

 

System altered.

 

SQL>

I created a user with the new profile:

SQL> create user andrew

  2  identified by reid

  3  profile for_andrew

  4  /

 

User created.

 

SQL> grant create session,

  2  select any dictionary to andrew

  3  /

 

Grant succeeded.

 

SQL>

I logged in with this user, ran some SQL against dba_tables and counted the session logical reads this had consumed. For the purposes of this simple demonstration, I ignored any overhead which the 2^nd piece of SQL may have incurred:

SQL> conn andrew/reid

Connected.

SQL> select max(last_analyzed) from dba_tables

  2  /

 

MAX(LAST_

---------

18-OCT-15

 

SQL> select value from v$sesstat a, v$statname b

  2  where sid =

  3  (select distinct sid from v$mystat)

  4  and a.statistic# = b.statistic#

  5  and name = 'session logical reads'

  6  /

 

       VALUE

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

        6936

 

SQL>

I logged in again ran some SQL against dba_indexes and counted the session logical reads this had consumed. Again, I ignored any overhead which may have been incurred by checking the session logical reads figure in v$sesstat:

SQL> conn andrew/reid

Connected.

SQL> select max(last_analyzed) from dba_indexes

  2  /

 

MAX(LAST_

---------

18-OCT-15

 

SQL> select value from v$sesstat a, v$statname b

  2  where sid =

  3  (select distinct sid from v$mystat)

  4  and a.statistic# = b.statistic#

  5  and name = 'session logical reads'

  6  /

 

       VALUE

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

        7341

 

SQL>

The 2 statements together used over 14000 session logical reads. I guessed that if I tried to run them in the same session, this would exceed the limit set by the logical_reads_per_session parameter in the user’s profile. I logged in again and tried to do this. As expected, the 1^st SQL worked but the 2^nd failed with an ORA-02394:

SQL> conn andrew/reid

Connected.

SQL> select max(last_analyzed) from dba_tables

  2  /

 

MAX(LAST_

---------

18-OCT-15

 

SQL> select max(last_analyzed) from dba_indexes

  2  /

select max(last_analyzed) from dba_indexes

                               *

ERROR at line 1:

ORA-02394: exceeded session limit on IO usage, you are

being logged off

 

SQL>

V$SYSTEM_EVENT

This was tested on Oracle 11.2. V$SYSTEM_EVENT shows what an instance has been waiting for since it was last started. You can see the top 10 events (by total time waited) as follows. The times are in hundredths of a second:

SQL> l

  1  select * from

  2  (select event, time_waited

  3   from v$system_event

  4   where wait_class != 'Idle'

  5   order by 2 desc)

  6* where rownum <= 10

SQL> /

 

EVENT                               TIME_WAITED

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

control file sequential read             992637

db file sequential read                  569680

control file parallel write              543468

os thread startup                        515992

log file parallel write                  499896

db file parallel write                   426726

db file scattered read                   202302

log file sync                            159840

Disk file operations I/O                  45765

ADR block file read                       29553

 

10 rows selected.

 

SQL>

 

If you include Idle events, you see the wait events where the database wasn’t doing anything. The SQL*Net message from client event, for example, records how long the database spent waiting for its next instruction. This may not be what you want to see:

SQL> l

  1  select * from

  2  (select event, time_waited

  3   from v$system_event

  4   order by 2 desc)

  5* where rownum <= 10

SQL> /

 

EVENT                                    TIME_WAITED

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

rdbms ipc message                         1956293654

SQL*Net message from client                637129764

DIAG idle wait                             326433989

dispatcher timer                           163322456

shared server idle wait                    163320698

Streams AQ: qmn coordinator idle wait      163318553

Streams AQ: qmn slave idle wait            163315578

smon timer                                 163264804

pmon timer                                 163252749

Space Manager: slave idle wait             163171812

 

10 rows selected.

 

SQL>

 

The TIME_WAITED for SQL*Net message from client works out at almost 74 days. However, the database has been open for less than 20 days:

 

SQL> l

  1  select startup_time, sysdate

  2* from v$instance, dual

SQL> /

 

STARTUP_TIME SYSDATE

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

04-MAY-12    23-MAY-12

 

SQL>

 

That’s because the TIME_WAITED values are the sum of all the TIME_WAITED values for all the sessions which have logged in since the database was opened.

 

If you combine these figures with the CPU time used, you start to get an idea of what your database has been doing:

 

SQL> l

  1  select a.name, b.value

  2  from v$statname a, v$sysstat b

  3  where a.statistic# = b.statistic#

  4* and a.name = 'CPU used by this session'

SQL> /

 

NAME                                     VALUE

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

CPU used by this session               1854863

 

SQL>

CPU Usage

I tested this on Oracle 11.2. You need to be careful when looking at Oracle statistics on CPU usage. Here is an idle session (in red):

SQL> select distinct sid from v$mystat

  2  /

 

       SID

----------

         6

 

SQL>

 

Here is its CPU usage as seen from another session (in blue). The CPU used when call started and CPU used by this session figures are in hundredths of a second. The DB CPU figure is in microseconds:

 

SQL> select

  2  (select value from v$sesstat a, v$statname b

  3   where sid = 6

  4   and a.statistic# = b.statistic#

  5   and name = 'CPU used when call started') as CUWCS,

  6  (select value from v$sesstat a, v$statname b

  7   where sid = 6

  8   and a.statistic# = b.statistic#

  9   and name = 'CPU used by this session') as CUBTS,

10  (select value

11   from v$sess_time_model

12   where sid = 6

13   and stat_name = 'DB CPU') as "DB CPU"

14  from dual

15  /

 

     CUWCS      CUBTS     DB CPU

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

     41669      41669  416810000

 

SQL>

 

The first session runs a query:

 

SQL> set timing on

SQL> select count(*) from dba_tables a, dba_tables b

  2  /

 

While this is going on, the second session monitors it every 30 seconds The  CPU used when call started figure stays the same while the SQL is running. This is reasonable. The CPU used by this session figure goes up a little then stays the same. It is not clear what this is measuring at all. The DB CPU figure appears to be updated regularly:

 

SQL> /

 

     CUWCS      CUBTS     DB CPU

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

     41669      41752  441270000

 

SQL> /

 

     CUWCS      CUBTS     DB CPU

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

     41669      41752  470980000

 

SQL> /

 

     CUWCS      CUBTS     DB CPU

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

     41669      41752  494630000

 

SQL> /

 

     CUWCS      CUBTS     DB CPU

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

     41669      41752  522780000

 

SQL>

 

The first session’s query finishes:

 

SQL> select count(*) from dba_tables a, dba_tables b

  2  /

 

  COUNT(*)

----------

   9369721

 

Elapsed: 00:02:25.93

SQL>

 

Then the figures in the second session match again:

 

SQL> /

 

     CUWCS      CUBTS     DB CPU

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

     54891      54891  549030000

 

SQL>

V$MYSTAT

Tested on Oracle 11.2. This view stores information for the current session:

 

SQL> desc v$mystat

Name                       Null?    Type

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

SID                                 NUMBER

STATISTIC#                          NUMBER

VALUE                               NUMBER

 

SQL>

 

Although there is a column called SID in the view, it only has 1 value, the SID for the current session:

 

SQL> select distinct sid from v$mystat

  2  /

 

       SID

----------

       394

 

SQL>

 

If you join it with v$statname, you can pick out individual statistics like this:

 

SQL> select value/100 CPU_used

  2  from v$mystat a, v$statname b

  3  where a.statistic# = b.statistic#

  4  and name = 'CPU used by this session'

  5  /

 

  CPU_USED

----------

       .03

 

SQL>

 

An ideal way to use lots of CPU time is to have a join without a join condition:

 

SQL> set timing on

SQL> select count(*)

  2  from dba_tables a, dba_tables b

  3  /

 

  COUNT(*)

----------

   9375844

 

Elapsed: 00:03:29.23

SQL> set timing off

 

Now that the SQL has finished, you can see that the elapsed time was 209 seconds and the CPU time used was 144 seconds:

 

SQL> select value/100 CPU_used

  2  from v$mystat a, v$statname b

  3  where a.statistic# = b.statistic#

  4  and name = 'CPU used by this session'

  5  /

 

  CPU_USED

----------

    144.23

 

SQL>