what one can learn from a simple one row update

May 1, 2012 — Leave a comment

what happens when you update a row of a table ? not much, you could think. but in fact there are lots and lots of things happening in the background from which you can learn how the database works. this post will follow a simple one row update and shows what’s happening behind the scenes.

i will start by creating a tiny little table and adding one row to it:

CREATE TABLE T1 ( A NUMBER )
       TABLESPACE USERS;
INSERT INTO T1 (A)
       VALUES (1);
COMMIT;

this is the starting point. because we will need this information later lets record four things:
1) the block number of the row we just created
2) the object id of the table in the data dictionary
3) the sid of the session
4) the session’s address

-- rowid of the row
SELECT rowid
  FROM t1
 WHERE A = 1;
ROWID
------------------
AAADb4AAEAAAAF9AAA
-- block number of the row
SELECT dbms_rowid.rowid_block_number('AAADb4AAEAAAAF9AAA') block_no
  FROM dual;
BLOCK_NO
----------
381
-- object id of the table
SELECT object_id
  FROM all_objects
 WHERE owner = USER
   AND object_type = 'TABLE'
   AND object_name = 'T1';
OBJECT_ID
----------
14072
-- the session id of the session which sends the update
SELECT SYS_CONTEXT('userenv','SID') sid
  FROM dual;
SID
---
32
-- the same sessions address
SELECT saddr
  FROM v$session
 WHERE sid = 32;
SADDR
----------------
000000006F680A28

so by now we know the object id ( which is 14072 ), the block number of the block containing the row ( which is 381 ), the session id ( which is 32 in my case ) and the session’s address ( which is 000000006F680A28 ).

ready to update ?

UPDATE T1
SET A = 2
WHERE A = 1;
1 row updated.

at this point it is important to leave the transaction open ( to not commit ). i will start a second sqlplus session and leave the session which issues the update as is.

the obvious things first. each insert/update/delete will start a transaction and as we did not commit our update we should be able to see the transaction:

SELECT addr
, ubafil
, ubablk
, ubarec
, status
, xid
, start_scn
FROM v$transaction
WHERE ses_addr = '000000006F680A28';
ADDR UBAFIL UBABLK UBAREC STATUS XID START_SCN
---------------- ---------- ---------- ---------- ------ ---------------- ----------
000000006DF332D8 3 483 11 ACTIVE 0100100022010000 958658

as expected there is an active transaction for our update statement. because each transaction will change some data ( if there is not rollback ) some undo must be generated. from the output above we can learn:
1. the datafile containing the undo block has file number 3
2. the block containing the undo is block number 483
3. the undo record is 11

before taking a look at the undo block lets see what information oracle has about our data block in v$bh ( which lists the buffer headers ):

col dirty for a5
col temp for a5
col ping for a5
col stale for a5
col stale for a5
col direct for a5
col status for a6
col objd for 99999
col block# for 999999
SELECT file#
, status
, dirty
, temp
, ping
, stale
, direct
, objd
, block#
FROM v$bh
WHERE objd = 14072
AND block# = 381;
FILE# STATUS DIRTY TEMP PING STALE DIREC OBJD BLOCK#
---------- ------ ----- ----- ----- ----- ----- ------ -------
4 cr N N N N N 14072 381
4 xcur N N N N N 14072 381

so v$bh reports two copies of the block header, one in “consitent read” the other in “exclusive” mode non of them dirty, temporary, pinged, stale or direct.

the exclusive one is the original block while the cr one is the copy we got when we issued the update. if you’d do a rollback of the update and resend the same update statement you’d receive another “cr” copy of the block. can you imagine why ? because readers do not block writers and writers do not block readers. for others sessions to be able to view the block as it really is ( the update is not yet commited ) oracle creates copies of blocks to construct a read consistant view of the data. you should keep this in mind when sizing your pools.

happily oracle provides a way to look at the contents of a block. lets do a dump of our undo block:

ALTER SESSION SET TRACEFILE_IDENTIFIER='my_dumps';
ALTER SYSTEM DUMP DATAFILE 3 BLOCK 483;

as the select from v$transaction tells us that our undo record is 11, we will take a look at this record only. if you open the trace file scroll down to your undo record you should see a similar output than this:

*-----------------------------
* Rec #0xb slt: 0x10 objn: 14072(0x000036f8) objd: 14072 tblspc: 4(0x00000004)
* Layer: 11 (Row) opc: 1 rci 0x00
Undo type: Regular undo Begin trans Last buffer split: No
Temp Object: No
Tablespace Undo: No
rdba: 0x00000000Ext idx: 0
flg2: 0
*-----------------------------
uba: 0x00c001e3.0036.09 ctl max scn: 0x0000.000e4630 prv tx scn: 0x0000.000e4631
txn start scn: scn: 0x0000.000ea07f logon user: 42
prev brb: 12583394 prev bcl: 0
KDO undo record:
KTB Redo
op: 0x03 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: Z
Array Update of 1 rows:
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 0 ckix: 0
ncol: 1 nnew: 1 size: 0
KDO Op code: 21 row dependencies Disabled
xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x0100017d hdba: 0x0100017a
itli: 2 ispac: 0 maxfr: 4858
vect = 0
col 0: [ 2] c1 02

if you wonder why this is record 11, “#0xb” translates to 11:

select to_number('b','X') dec
from dual;
DEC
----------
11

what can we learn from here:
1) we can see the tablespace number and the object which is affected:

* Rec #0xb slt: 0x10 objn: 14072(0x000036f8) objd: 14072 tblspc: 4(0x00000004)

2) the start scn ( system change number ) is recorded as long with the user who started the transaction

txn start scn: scn: 0x0000.000ea07f logon user: 42

000e2f90 translates to 929670 and 42 is the user_id reported in all_users for the user who started the transaction.
3) one row will be updated:

Array Update of 1 rows:
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 0 ckix: 0
ncol: 1 nnew: 1 size: 0
KDO Op code: 21 row dependencies Disabled
xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x0100017d hdba: 0x0100017a
itli: 2 ispac: 0 maxfr: 4858
vect = 0
col 0: [ 2] c1 02

other people described the meanings of all the keywords and flags, so i will not just re-type them here ( you may, for example, want to check julian dyke’s website ).
for now, it is just important to notice that the first column of the table ( col 0 ) will be changed by 2 bytes ( [2] ) and the values is 1 ( 02 – 1 ).  oracle prefixes numeric values ( c1 ), so we may ignore the first 2 bytes.

what else is happening in the background? as stated in earlier posts, things need protections. lets see if we can find some locks for our session:

SELECT sid
, id1
, id2
, lmode
, request
FROM v$lock
WHERE sid = 32;
SID ID1 ID2 LMODE REQUEST
---------- ---------- ---------- ---------- ----------
32 100 0 4 0
32 14072 0 3 0
32 65552 290 6 0

the lmodes translate to: 4 = Edition enqueue (AE), 3 = DML (TM), 6 = Transaction (TX).

i am not sure, but i think the edition enqueue lock is always present ( happy if someone can tell more about this ).
our update triggered two locks, one for the dml and one for the transaction.
column id1 of the dml references our table, which is object 14072. we locked one row in shared exclusive mode.
column id2 of the transaction lock references the sequence of the transaction ( v$transaction.xidsqn ). so, the other way around, you can check the locks for your session and from there get to the object and transaction.

in my case, the redo containing the update must be the current one ( as nothing else is happening on my database ). so i’ll find one copy of it ( as the logs are mirrored ):

select GROUP#
, THREAD#
, SEQUENCE#
, STATUS
from v$log;
GROUP# THREAD# SEQUENCE# STATUS
---------- ---------- ---------- ---------------
1 1 85 INACTIVE
2 1 86 INACTIVE
3 1 87 CURRENT
select member
from v$logfile
where group# = 3;
MEMBER
------------------------------------------------------------------------------------------------------------------------
+DB112_DATA_DG/db112/onlinelog/group_3.259.779116045
+DB112_ARCH_DG/db112/onlinelog/group_3.259.779116047

… dump the first one:

alter system dump logfile '+DB112_DATA_DG/db112/onlinelog/group_3.259.779116045';

… and you will find the redo record:

REDO RECORD - Thread:1 RBA: 0x000057.000000a2.0010 LEN: 0x01fc VLD: 0x0d
SCN: 0x0000.000ea149 SUBSCN: 1 04/24/2012 20:10:42
(LWN RBA: 0x000057.000000a2.0010 LEN: 0002 NST: 0001 SCN: 0x0000.000ea149)
CHANGE #1 TYP:2 CLS:1 AFN:4 DBA:0x0100017d OBJ:14072 SCN:0x0000.000ea0c2 SEQ:1 OP:11.19 ENC:0 RBL:0
KTB Redo
op: 0x11 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0001.010.00000122 uba: 0x00c001e3.0036.0b
Block cleanout record, scn: 0x0000.000ea148 ver: 0x01 opt: 0x02, entries follow...
itli: 1 flg: 2 scn: 0x0000.000ea0c2
Array Update of 1 rows:
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 2 ckix: 0
ncol: 1 nnew: 1 size: 0
KDO Op code: 21 row dependencies Disabled
xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x0100017d hdba: 0x0100017a
itli: 2 ispac: 0 maxfr: 4858
vect = 0
col 0: [ 2] c1 03
CHANGE #2 TYP:0 CLS:17 AFN:3 DBA:0x00c00080 OBJ:4294967295 SCN:0x0000.000ea097 SEQ:1 OP:5.2 ENC:0 RBL:0
ktudh redo: slt: 0x0010 sqn: 0x00000122 flg: 0x0012 siz: 164 fbi: 0
uba: 0x00c001e3.0036.0b pxid: 0x0000.000.00000000
CHANGE #3 TYP:0 CLS:18 AFN:3 DBA:0x00c001e3 OBJ:4294967295 SCN:0x0000.000ea096 SEQ:2 OP:5.1 ENC:0 RBL:0
ktudb redo: siz: 164 spc: 6734 flg: 0x0012 seq: 0x0036 rec: 0x0b
xid: 0x0001.010.00000122
ktubl redo: slt: 16 rci: 0 opc: 11.1 [objn: 14072 objd: 14072 tsn: 4]
Undo type: Regular undo Begin trans Last buffer split: No
Temp Object: No
Tablespace Undo: No
0x00000000 prev ctl uba: 0x00c001e3.0036.09
prev ctl max cmt scn: 0x0000.000e4630 prev tx cmt scn: 0x0000.000e4631
txn start scn: 0x0000.000ea07f logon user: 42 prev brb: 12583394 prev bcl: 0 BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo
op: 0x03 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: Z
Array Update of 1 rows:
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 0 ckix: 0
ncol: 1 nnew: 1 size: 0
KDO Op code: 21 row dependencies Disabled
xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x0100017d hdba: 0x0100017a
itli: 2 ispac: 0 maxfr: 4858
vect = 0
col 0: [ 2] c1 02

what can we see here:
1) there is our update “col 0: [ 2] c1 03”: change the first column of our table to 2 ( 03 – 1 ).
2) there is the same undo entry as in the undo block a little later in the trace: “col 0: [ 2] c1 02”.

why is there the same entry in the redo as we found it in the undo ? remember that we did not yet finish our transaction ( the commit is still pending ). so what will happen if the instance crashes now? when the instance comes up again after the crash oracle will scan the redo logs and apply all the changes that happened up to before the crash. and as we did not commit the transaction oracle must do a rollback, and that’s what the redo entry is about ( redo the undo ).

lets commit the update in the initial session and check what changed.

commit;

what happened to our transaction:

SELECT addr
, ubafil
, ubablk
, ubarec
, status
, xid
, start_scn
FROM v$transaction
WHERE ses_addr = '000000006F680A28';
no rows selected

as expected, the transaction finished.

our locks?

SELECT sid
, id1
, id2
, lmode
, request
FROM v$lock
WHERE sid = 32;
SID TYPE ID1 ID2 LMODE REQUEST
SID ID1 ID2 LMODE REQUEST
---------- ---------- ---------- ---------- ----------
32 100 0 4 0

gone, too.

the buffer headers ?

SELECT file#
, status
, dirty
, temp
, ping
, stale
, direct
, objd
, block#
FROM v$bh
WHERE objd = 14072
AND block# = 381;
FILE# STATUS DIRTY TEMP PING STALE DIREC OBJD BLOCK#
---------- --------------- ----- ----- ----- ----- ----- ------ -------
4 cr N N N N N 14072 381
4 xcur Y N N N N 14072 381

the dirty flag for our buffer changed to ‘Y’, so there was some modification. obvious, as we changed the row.

just for completion: if you do a rollback instead of the commit you’d get another redo entry describing the rollback.

again this is far from being complete but should give you some hints on what is happening behind the scenes. and, even more important: every change to the database is recorded in the log files ( and this includes undo generation ).

Advertisements

No Comments

Be the first to start the conversation!

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s