Alexander Anokhin

What’s new in DTrace LIO?
Jump to introduction: Dynamic tracing of Oracle logical I/O

1. The list of supported functions performing logical I/O is extended:
Note: some function names below are my suggestions.

Consistent gets:

• kcbgtcr – Kernel Cache Buffer Get Consistent Read. This is general entry point for consistent read.
• kcbldrget – Kernel Cache Buffer Load Direct-Read Get. The function performing direct-path read. Interesting detail: 10.2 the function kcbldrget is called just after kcbgtcr, in 11.2 by (from) kcbgtcr.

Current gets (db block gets):

• kcbgcur – Kernel Cache Buffer Get Current Read
• kcbget – Kernel Cache Buffer Get Buffer. This is analogue of kcbgcur function, as I observed this function is called for index branch and leaf blocks
• kcbnew – Kernel Cache Buffer New Buffer
• kcblnb (kcblnb_dscn in 11.2) – Kernel Cache Buffer Load New Buffer. The function performing direct-path load. Decoding of block coordinates is not supported for this function in the current version of DTraceLIO. The parameters such as object_id, data_object_id will be shown as 0 (zero)

Note: KCB and KCBL are module names
KCB – Kernel Cache Buffer (Get, change, and release buffers)
KCBL – Kernel Cache Buffer Load (Direct I/O routines)

2. Functions related with buffer pinning are added.
Following functions calls are traced:

• kcbispnd – Kernel Cache Buffer Is Pinned – functions where Oracle checks is some buffer pinned yet or not. In this function Oracle either increments statistic “buffer is pinned count” if buffer is pinned yet or “buffer is not pinned count” if buffer is not pinned.
• kcbrls – Kernel Cache Buffer Release Pin

Important note: buffer pinning itself is performed inside logical I/O functions. So, unfortunately it is impossible to see it as function calls.

3. Changed parameters
Usage:
dtracelio.d PID [show_each_call] [interval]

• PID – unix process ID
• show_each_call – This is the bitmask determining how functions calls will be shown.
  1st bit – to show logical I/O functions
  2nd bit – to show buffer pinning
  Examples:
  0: output of each call will be disabled
  1: logical I/O functions will be shown
  3: logical I/O and buffer pinning functions will be shown
  Default value: 1 (only logical I/O functions will be shown)
• interval – Specifies the number of seconds over which Summary form with cumulative figures will be shown. Works only when show_each_call is disabled.
  Default value: 0 (disabled)

4. Existed summary table is changed, new columns are added
The existent summary table “Logical I/O Summary (grouped by function/object)” is changed.

============================= Logical I/O Summary (grouped by function/object) ===========================
 function    stat   object_id   data_object_id   mode_held   where     bufs     calls
--------- ------- ----------- ---------------- ----------- ------- -------- ---------
  kcbgcur      cu           0               -1           2     381        1         1
  kcbgcur      cu       56756            56756           2     594        1         1
   kcbnew      cu           0               -1                 383        1         1
  kcbgtcr      cr       56756            56756                 446        2         2
  kcbgtcr      cr       56756            56756                 447        2         2
  kcbgtcr      cr       56756            56756                 577        2         2
==========================================================================================================

New columns:

• stat: “cr” – consistent get, “cr (d)” – consistent get direct, “cu” – current get, “cu (d)” – current get direct
• mode_held: mode in which buffer is pinned. The column is supported only for functions kcbgcur and kcbget
• bufs: number of processed bufers. This number is equal number of calls for almost all functions except kcbnew. In function kcbnew N (many) buffers can be processed by one function call.

5. New summary table is added

In addition to old summary output grouped by function/object new output form “grouped by object” is added.

An example:

================================= Logical I/O Summary (grouped by object) ================================
 object_id  data_object_id       lio        cr    cr (d)        cu    cu (d) ispnd (Y) ispnd (N)   pin rls
---------- --------------- --------- --------- --------- --------- --------- --------- --------- ---------
         1              -1        21         0         0        21         0         0         0        21
        17              17       108       108         0         0         0         0         0       108
         0              -1     64042        18         0     64024         0         0         0        36
    415893         2142703    463565     49351         0    414214         0         0    387842     88604
   2142704         2142704   1977665         0         0   1977665         0         0         0      9467
---------- --------------- --------- --------- --------- --------- --------- --------- --------- ---------
     total                   2505401     49477         0   2455924         0    387842         0     98236
==========================================================================================================

Where following figures are showed:

• lio – All logical reads done by an object. Equal of “session logical reads” statistic. lio = cr + cu
• cr – consistent gets. This statistic includes cr (d)
• cr (d) – consistent gets direct
• cu – current gets. This statistic includes cu (d)
• cu (d) – current gets direct
• ispnd (Y) – buffer is pinned count
• ispnd (N) – buffer is not pinned count
• pin rls – buffer pin is released

The list of objects is sorted by lio column.

Enjoy!😉

p.s.
Announcement: One of the next blog entry will be about statistics “buffer is [not] pinned count”. I will show what these statistics do mean, how it works and how DTraceLIO with new functionality might be used.
Coming soon.