The in-efficiency of the Oracle Server

From: <xg_at_oraclexg.com>
Date: 23 Mar 2006 01:23:54 -0800
Message-ID: <1143105834.438428.281720@t31g2000cwb.googlegroups.com>

The following note is with reference to updating an integer column in a 1024
row, 5 column, table. We are running single process. Each row update generates
400 bytes of redo.

Of 273 Direct I/O's we have:

sfwfb (write) 240
sfrfb (read)   21
sfofi (open)   12.

Additionally, we have 12 sfcfi's (close) but I think they affect the Buffered
I/O count. 12 is a reasonable amount since we do 12 sfofi's.

REDO WRITES (131 -- 55%)

kcfwbd - write database blocks.
kcrfsy - sync dirty redo buffers to disk.
kcrpch - put redo header to disk.

kcbchg calls kcrfwr 95 times which results in 95 writes.
kcbchg calls kcrfsy 28 times which results in 28 writes.
kcrpch, additionally,              results in  8 writes.

UNDO WRITES (84 -- 35%)

ktugur - generate undo redo.

ktugur calls kcbget 84 times. In turn, kcbget (indirectly) calls kcrfsy 42
times which result in 42 writes via kcriop and, additionally, also makes 42
indirect calls to kcfwbd which result in as many writes.

TABLE SCAN WRITES (25 -- 10%)

kdstscy - cycle through slots.

kdstscy results in 25 writes via kcfwbd. Considering kdstscy scans slots
it is odd that it is performing I/O.

NOTEWORTHY POINT

Eliminating redo results in 70 Direct I/O's. These I/O's, primarily writes, are a consequence of ktugur (45) and kdstscy (25). Also, the cpu time drops from 7.65s to 6.43s.

Since the sync I/O's of the undo are a consequence of the redo it would be (?) appropriate to attribute the I/O's in the following way:

Redo (95+28+8+42) 173  -- 72%
Undo (42)          42  -- 18%
Scan (25)          25  -- 10%

Received on Thu Mar 23 2006 - 03:23:54 CST