Delayed block cleanout and ORA-01555

They say delayed block cleanout could cause ORA-01555 and in this post, I did an experiment to try to explain why.

–We first alter database undo management as MANUAL and create tablespace and rollback segment
drop tablespace rbs_ts including contents and datafiles;
create tablespace rbs_ts datafile size 5M autoextend off extent management local segment space management manual uniform size 100K;

create rollback segment rbs_one tablespace rbs_ts;
alter rollback segment rbs_one online;

create rollback segment rbs_two tablespace rbs_ts;
alter rollback segment rbs_two online;

drop table t1 purge;
create table t1(id number, name varchar2(64));

— insert data into table
begin
for i in 1..1000 loop
insert into t1 values(
i, ‘INITIAL VALUE OF COLUMN’);
end loop;
end;
/

commit;

alter system flush buffer_cache;

— find the file and block these data went to:
select
dbms_rowid.rowid_relative_fno(rowid) File#,
dbms_rowid.rowid_block_number(rowid) Block#,
count(1)
from t1
group by
dbms_rowid.rowid_relative_fno(rowid),
dbms_rowid.rowid_block_number(rowid)
order by 1,2
/

FILE# BLOCK# COUNT(1)
———- ———- ———-
4 435 117
4 436 223
4 437 220
4 438 220
4 439 220

— identify rows in a specific block
select min(id), max(id), count(id)
from t1
where dbms_rowid.rowid_block_number(rowid) = 436;

MIN(ID) MAX(ID) COUNT(ID)
———- ———- ———-
1 223 223

select DBMS_ROWID.ROWID_OBJECT(rowid) “OBJECT”,
DBMS_ROWID.ROWID_RELATIVE_FNO(rowid) “FILE”,
DBMS_ROWID.ROWID_BLOCK_NUMBER(rowid) “BLOCK”,
DBMS_ROWID.ROWID_ROW_NUMBER(rowid) “ROW”
from T1
where id=1;

OBJECT FILE BLOCK ROW
———- ———- ———- ———-
15504 4 436 0

— check block state in buffer cache
set lines 200 pages 200
col object_name for a30
select b.dbarfil, b.dbablk, b.class,
decode(state, 0, ‘free’,
1, ‘xcur’,
2, ‘scur’,
3, ‘cr’,
4, ‘read’,
5, ‘mrec’,
6, ‘irec’,
7, ‘iwrite’,
8, ‘pi’,
9, ‘memory’,
10, ‘mwrite’,
11, ‘donated’) as state,
cr_scn_bas, cr_scn_wrp, cr_uba_fil, cr_uba_blk, cr_uba_seq,
(select object_name from dba_objects where object_id = b.obj) as object_name
from sys.x$bh b
where dbarfil = 4
and dbablk = 436;

DBARFIL DBABLK CLASS STATE CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ OBJECT_NAME
———- ———- ———- ——- ———- ———- ———- ———- ———- ——————————
4 436 1 free 0 0 0 0 0 T1
4 436 1 free 0 0 0 0 0 T1

— dump datafile to check current ITL information as sysdba
oradebug setmypid
oradebug tracefile_name
/oraapp/oracle/diag/rdbms/mydb/mydb/trace/mydb_ora_20905.trc

alter system checkpoint;
alter system dump datafile 4 block 436;

—–
Block dump from disk:
buffer tsn: 4 rdba: 0x010001b4 (4/436)
scn: 0x0000.00296125 seq: 0x01 flg: 0x06 tail: 0x61250601
frmt: 0x02 chkval: 0xadec type: 0x06=trans data
Hex dump of block: st=0, typ_found=1

Block header dump: 0x010001b4
Object id on Block? Y
seg/obj: 0x3c90 csc: 0x00.296123 itc: 2 flg: E typ: 1 – DATA
brn: 0 bdba: 0x10001b0 ver: 0x01 opc: 0
inc: 0 exflg: 0

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x000c.008.00000002 0x01400024.0000.18 C— 0 scn 0x0000.002960f6
0x02 0x000c.00d.00000002 0x01400024.0000.20 –U- 1 fsc 0x0000.00296125
bdba: 0x010001b4

tab 0, row 0, @0x441
tl: 30 fb: –H-FL– lb: 0x2 cc: 2
col 0: [ 2] c1 02
col 1: [23]
49 4e 49 54 49 41 4c 20 56 41 4c 55 45 20 4f 46 20 43 4f 4c 55 4d 4e
———-

Now the enviroment has been setup and we can start changing our data.

Sess 1 (user caoff):
SET TRANSACTION USE ROLLBACK SEGMENT rbs_one;

update t1 set name=’AFTER UPDATE’ where id=1;

SQL> select dbms_transaction.local_transaction_id from dual;

LOCAL_TRANSACTION_ID
————————————————————————————————————————–
11.15.6

SQL> select current_scn, checkpoint_change# from v$database;

CURRENT_SCN CHECKPOINT_CHANGE#
———– ——————
2595633 2594082

Sess 3 (user caoff) :
SET TRANSACTION ISOLATION LEVEL SERIALIZABLE;
select current_scn, checkpoint_change# from v$database;

CURRENT_SCN CHECKPOINT_CHANGE#
———– ——————
2595734 2594082

update t1 set name=’AFTER UPDATE’ where id=443;

select DBMS_ROWID.ROWID_OBJECT(rowid) “OBJECT”,
DBMS_ROWID.ROWID_RELATIVE_FNO(rowid) “FILE”,
DBMS_ROWID.ROWID_BLOCK_NUMBER(rowid) “BLOCK”,
DBMS_ROWID.ROWID_ROW_NUMBER(rowid) “ROW”
from T1
where id=443;

OBJECT FILE BLOCK ROW
———- ———- ———- ———-
15504 4 437 219

set lines 200 pages 200
col object_name for a30
select b.dbarfil, b.dbablk, b.class,
decode(state, 0, ‘free’,
1, ‘xcur’,
2, ‘scur’,
3, ‘cr’,
4, ‘read’,
5, ‘mrec’,
6, ‘irec’,
7, ‘iwrite’,
8, ‘pi’,
9, ‘memory’,
10, ‘mwrite’,
11, ‘donated’) as state,
cr_scn_bas, cr_scn_wrp, cr_uba_fil, cr_uba_blk, cr_uba_seq,
(select object_name from dba_objects where object_id = b.obj) as object_name
from sys.x$bh b
where dbarfil = 4
and dbablk = 437;

DBARFIL DBABLK CLASS STATE CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ OBJECT_NAME
———- ———- ———- ——- ———- ———- ———- ———- ———- ——————————
4 437 1 xcur 0 0 0 0 0 T1
4 437 1 cr 2712462 0 0 0 0 T1

Sess 2(user dba):
set lines 200 pages 200
col object_name for a30
select b.dbarfil, b.dbablk, b.class,
decode(state, 0, ‘free’,
1, ‘xcur’,
2, ‘scur’,
3, ‘cr’,
4, ‘read’,
5, ‘mrec’,
6, ‘irec’,
7, ‘iwrite’,
8, ‘pi’,
9, ‘memory’,
10, ‘mwrite’,
11, ‘donated’) as state,
cr_scn_bas, cr_scn_wrp, cr_uba_fil, cr_uba_blk, cr_uba_seq,
(select object_name from dba_objects where object_id = b.obj) as object_name
from sys.x$bh b
where dbarfil = 4
and dbablk = 436;

DBARFIL DBABLK CLASS STATE CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ OBJECT_NAME
———- ———- ———- ——- ———- ———- ———- ———- ———- ——————————
4 436 1 cr 2712293 0 5 10 52 T1
4 436 1 cr 2712293 0 5 10 52 T1
4 436 1 xcur 0 0 0 0 0 T1
4 436 1 cr 2712282 0 0 0 0 T1

alter system dump datafile 4 block 436;

—–
scn: 0x0000.00296125 seq: 0x01 flg: 0x06 tail: 0x61250601
—–

alter system flush buffer_cache;

———–
Block dump from disk:
buffer tsn: 4 rdba: 0x010001b4 (4/436)
scn: 0x0000.0029638d seq: 0x01 flg: 0x04 tail: 0x638d0601
frmt: 0x02 chkval: 0x0717 type: 0x06=trans data
Hex dump of block: st=0, typ_found=1

Block header dump: 0x010001b4
Object id on Block? Y
seg/obj: 0x3c90 csc: 0x00.29638d itc: 2 flg: E typ: 1 – DATA
brn: 0 bdba: 0x10001b0 ver: 0x01 opc: 0
inc: 0 exflg: 0

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x000b.006.000000f5 0x0140000a.0034.10 —- 1 fsc 0x000b.00000000
0x02 0x000c.00d.00000002 0x01400024.0000.20 C— 0 scn 0x0000.00296125
bdba: 0x010001b4

tab 0, row 0, @0x42e
tl: 19 fb: –H-FL– lb: 0x1 cc: 2
col 0: [ 2] c1 02
col 1: [12] 41 46 54 45 52 20 55 50 44 41 54 45 <– The block has been flushed to disk. Note that the transaction has not committed.
———–

Sess 1 (user caoff):
SQL> select current_scn, checkpoint_change# from v$database;

CURRENT_SCN CHECKPOINT_CHANGE#
———– ——————
2712596 2712231

commit;

Sess 2 (user dba):

alter system dump datafile 4 block 436;

————————
scn: 0x0000.0029638d seq: 0x01 flg: 0x04 tail: 0x638d0601 <– commit does not necessarily wake up DBWR
———————–

alter system checkpoint;

— ITL information still not cleaned because the block was not dirty in buffer cache.

— check undo information:

alter system dump undo header ‘RBS_ONE’;

TRN TBL::

index state cflags wrap# uel scn dba parent-xid nub stmt_num
————————————————————————————————
0x00 9 0x80 0x00f5 0x0001 0x0000.00295fe3 0x00000000 0x0000.000.00000000 0x00000000 0x00000000
0x01 9 0x80 0x00f5 0x0002 0x0000.00295ff1 0x00000000 0x0000.000.00000000 0x00000000 0x00000000
0x02 9 0x00 0x00f5 0x0003 0x0000.00296168 0x0140000a 0x0000.000.00000000 0x00000001 0x00000000
0x03 9 0x00 0x00f5 0x0004 0x0000.002961ce 0x0140000a 0x0000.000.00000000 0x00000001 0x00000000
0x04 9 0x00 0x00f5 0x0005 0x0000.002961ea 0x0140000a 0x0000.000.00000000 0x00000001 0x00000000
0x05 9 0x00 0x00f5 0x0007 0x0000.0029624a 0x0140000a 0x0000.000.00000000 0x00000001 0x00000000
–>0x06 9 0xc0 0x00f5 0xffff 0x0000.00296419 0x0140000a 0x0000.000.00000000 0x00000001 0x00000000

select dbms_utility.data_block_address_file(to_number(‘0140000a’,’xxxxxxxx’)) FILE#,
dbms_utility.data_block_address_block(to_number(‘0140000a’,’xxxxxxxx’)) BLOCK#
from dual;

FILE# BLOCK#
———- ———-
5 10

alter system dump datafile 5 block 10;

*—————————–
* Rec #0x10 slt: 0x06 objn: 15504(0x00003c90) objd: 15504 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: 0x0140000a.0034.0c ctl max scn: 0x0000.002910b3 prv tx scn: 0x0000.002910b3
txn start scn: scn: 0x0000.002962db logon user: 52
prev brb: 0 prev bcl: 0
KDO undo record:
KTB Redo
op: 0x04 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: L itl: xid: 0x000c.008.00000002 uba: 0x01400024.0000.18
flg: C— lkc: 0 scn: 0x0000.002960f6
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010001b4 hdba: 0x010001b2
itli: 1 ispac: 0 maxfr: 4858
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 0 ckix: 0
ncol: 2 nnew: 1 size: 11
col 1: [23]
49 4e 49 54 49 41 4c 20 56 41 4c 55 45 20 4f 46 20 43 4f 4c 55 4d 4e <– here is the undo info

— Next we do many transactions in the same block:
Sess 1 (user caoff):
begin
for i in 1..100000 loop
SET TRANSACTION USE ROLLBACK SEGMENT rbs_one;
update t1 set name=’ORA-1555 TEST’ where id=2;
commit;
end loop;
end;
/

— check undo information
— information in transaction table was overwritten

TRN TBL::

index state cflags wrap# uel scn dba parent-xid nub stmt_num
————————————————————————————————
0x00 9 0xc0 0x04f3 0x0001 0x0000.002f7ae0 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000
0x01 9 0xc0 0x04f3 0x0002 0x0000.002f7ae4 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000
0x02 9 0xc0 0x04f3 0x0003 0x0000.002f7ae8 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000
0x03 9 0xc0 0x04f3 0x0004 0x0000.002f7aec 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000
0x04 9 0xc0 0x04f3 0x0005 0x0000.002f7af0 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000
0x05 9 0xc0 0x04f3 0x0007 0x0000.002f7af4 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000
–>0x06 9 0xc0 0x04f3 0x000d 0x0000.002f7b10 0x0140001e 0x0000.000.00000000 0x00000001 0x00000000

undo information was also overwritten:

*—————————–
* Rec #0x10 slt: 0x30 objn: 15504(0x00003c90) objd: 15504 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: 0x0140000a.00ea.0f ctl max scn: 0x0000.002ec750 prv tx scn: 0x0000.002ec754
txn start scn: scn: 0x0000.002ec8db logon user: 52
prev brb: 20971552 prev bcl: 0
KDO undo record:
KTB Redo
op: 0x04 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: L itl: xid: 0x000b.02e.0000047d uba: 0x0140000a.00ea.0e
flg: C— lkc: 0 scn: 0x0000.002ec8d4
Array Update of 1 rows:
tabn: 0 slot: 1(0x1) flag: 0x2c lock: 0 ckix: 11
ncol: 2 nnew: 1 size: 0
KDO Op code: 21 row dependencies Disabled
xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x010001b4 hdba: 0x010001b2
itli: 1 ispac: 0 maxfr: 4858
vect = 3
col 1: [13] 4f 52 41 2d 31 35 35 35 20 54 45 53 54

block header has been updated:
—————————-
Block dump from disk:
buffer tsn: 4 rdba: 0x010001b4 (4/436)
scn: 0x0000.002ec914 seq: 0x01 flg: 0x06 tail: 0xc9140601
frmt: 0x02 chkval: 0xef2c type: 0x06=trans data
Hex dump of block: st=0, typ_found=1

Block header dump: 0x010001b4
Object id on Block? Y
seg/obj: 0x3c90 csc: 0x00.2ec912 itc: 2 flg: E typ: 1 – DATA
brn: 0 bdba: 0x10001b0 ver: 0x01 opc: 0
inc: 0 exflg: 0

Itl Xid Uba Flag Lck Scn/Fsc
0x01 0x000b.03e.0000047d 0x0140000a.00ea.1e –U- 1 fsc 0x0000.002ec914
0x02 0x000b.03d.0000047d 0x0140000a.00ea.1d C— 0 scn 0x0000.002ec910
bdba: 0x010001b4

tab 0, row 0, @0x42e
tl: 19 fb: –H-FL– lb: 0x0 cc: 2
col 0: [ 2] c1 02
col 1: [12] 41 46 54 45 52 20 55 50 44 41 54 45
—————————-

Sess 3 (user caoff):

SQL> select dbms_transaction.local_transaction_id from dual;

LOCAL_TRANSACTION_ID
————————
12.14.4

SQL> select * from t1 where id=1;
select * from t1 where id=1
*
ERROR at line 1:
ORA-01555: snapshot too old: rollback segment number 11 with name “RBS_ONE” too small

Conclusion:

1 During consistent read, undo information needed to build CR block means both undo record and rollback segment header. When the rollback segment header was reused and there is undo information to retrive an older version of the rollback segment header, the CR block still could be built.
2 In order to generate ORA-01555 error in your experiment, try small rollback segment

Reference:

ORA-01555 “Snapshot too old” – Detailed Explanation (40689.1)

Simpler test steps:

Sess 1:

SET TRANSACTION USE ROLLBACK SEGMENT rbs_one;
update t1 set name=’AFTER UPDATE’ where id=1;

Sess 2:
SET TRANSACTION ISOLATION LEVEL SERIALIZABLE;
update t1 set name=’AFTER UPDATE’ where id=443;
Sess 1:
select current_scn, checkpoint_change# from v$database;
commit;

Note: id=xxx doesn’t matter as long as we can guarantee that the undo information could be overwritten
begin
for i in 1..100000 loop
SET TRANSACTION USE ROLLBACK SEGMENT rbs_one;
update t1 set name=’ORA-1555 TEST’ where id=444;
commit;
end loop;
end;
/

Sess 2:
SQL> select * from t1 where id=1;
select * from t1 where id=1
*
ERROR at line 1:
ORA-01555: snapshot too old: rollback segment number 11 with name “RBS_ONE” too small

 

Advertisements

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