When UPDATE becomes an INSERT


24.07.2017
by Kamil Stawiarski

During a research for VOODOO, we came across a lot of interesting stuff inside REDO.
One of my favourites is an UPDATE, becoming an INSERT 🙂

So let’s see what has happened – I performed the following update on a sample table:

1SQL> desc hr.VD_TEST_REPLICATION
2 Name                              Null?    Type
3 ----------------------------------------------------- -------- ------------------------------------
4 ID                            NOT NULL NUMBER
5 STRINGS                            VARCHAR2(4000)
6 TIME1                              TIMESTAMP(6)
7 TIME2                              TIMESTAMP(6) WITH LOCAL TIME ZONE
8 TIME3                              TIMESTAMP(6) WITH TIME ZONE
9 TIME4                              DATE
10 CLOB_DATA                          CLOB
11 BLOB_DATA                          BLOB
12 
13SQL> ;
14  1  update HR.VD_TEST_REPLICATION
15  2  set clob_data='Czwane cząsteczki Czechowa.',
16  3* strings='ola la la la la'
17SQL> /
18 
19101 rows updated.

The regular dump of redo log with an UPDATE looks like this:

1REDO RECORD - Thread:2 RBA: 0x00009d.000400b4.0050 LEN: 0x01e8 VLD: 0x01 CON_UID: 0
2SCN: 0x0000.0160a562 SUBSCN:362 07/24/2017 09:23:05
3CHANGE #1 CON_ID:0 TYP:0 CLS:52 AFN:2 DBA:0x008021b0 OBJ:4294967295 SCN:0x0000.0160a562 SEQ:25 OP:5.1 ENC:0 RBL:0 FLG:0x0000
4ktudb redo: siz: 216 spc: 4366 flg: 0x0022 seq: 0x031e rec: 0x19
5            xid:  0x0012.016.00001564
6ktubu redo: slt: 22 rci: 24 opc: 11.1 objn: 98618 objd: 98618 tsn: 7
7Undo type:  Regular undo       Undo type:  Last buffer split:  No
8Tablespace Undo:  No
9             0x00000000
10KDO undo record:
11KTB Redo
12op: 0x02  ver: 0x01
13compat bit: 4 (post-11) padding: 1
14op: C  uba: 0x008021b0.031e.18
15KDO Op code: URP row dependencies Disabled
16  xtype: XA flags: 0x00000000  bdba: 0x01c0015e  hdba: 0x01c000b2
17itli: 2  ispac: 0  maxfr: 4858
18tabn: 0 slot: 31(0x1f) flag: 0x2c lock: 2 ckix: 49
19ncol: 8 nnew: 2 size: -31
20col  1: [29]
21 63 69 65 70 c5 82 65 20 6b 6c 75 63 68 79 2c 20 6b 6f 73 74 75 63 68 79 20
22 40 40 21 21
23col  6: [39]
24 00 54 00 01 02 0c 80 80 00 02 00 00 00 01 00 00 00 3f 74 2b 00 13 40 90 00
25 0d 22 00 01 ee c8 01 00 02 01 c0 3a 5b 10
26CHANGE #2 CON_ID:0 TYP:0 CLS:1 AFN:7 DBA:0x01c0015e OBJ:98618 SCN:0x0000.0160a562 SEQ:63 OP:11.5 ENC:0 RBL:0 FLG:0x0000
27KTB Redo
28op: 0x02  ver: 0x01
29compat bit: 4 (post-11) padding: 1
30op: C  uba: 0x008021b0.031e.19
31KDO Op code: URP row dependencies Disabled
32  xtype: XA flags: 0x00000000  bdba: 0x01c0015e  hdba: 0x01c000b2
33itli: 2  ispac: 0  maxfr: 4858
34tabn: 0 slot: 31(0x1f) flag: 0x2c lock: 2 ckix: 49
35ncol: 8 nnew: 2 size: 31
36col  1: [15]  6f 6c 61 20 6c 61 20 6c 61 20 6c 61 20 6c 61
37col  6: [84]
38 00 54 00 01 02 0c 80 80 00 02 00 00 00 01 00 00 00 3f 75 b0 00 40 48 90 00
39 3a 00 00 36 01 00 43 00 7a 00 77 00 61 00 6e 00 65 00 20 00 63 00 7a 01 05
40 00 73 00 74 00 65 00 63 00 7a 00 6b 00 69 00 20 00 43 00 7a 00 65 00 63 00
41 68 00 6f 00 77 00 61 00 2e

In this particular redo record, we can see 2 changes:

  • CHANGE #1 – with OP:5.1 is an UNDO information
  • CHANGE #2 – with OP:11.5 is an actual UPDATE

We can see here, that column 1 changes from "cieple kluchy, kostuchy @@!!" to "ola la la la la". You can check it with simple query:

1SQL> ed
2Wrote file afiedt.buf
3 
4  1  select utl_raw.cast_to_varchar2(replace('63 69 65 70 c5 82 65 20 6b 6c 75 63 68 79 2c 20 6b 6f 73 74 75 63 68 79 20 40 40 21 21',' ','')),
5  2     utl_raw.cast_to_varchar2(replace('6f 6c 61 20 6c 61 20 6c 61 20 6c 61 20 6c 61',' ',''))
6  3* from dual
7SQL> /
8 
9UTL_RAW.CAST_TO_VARCHAR2(REPLACE('63696570C58265206B6C756368792C206B6F7374756368792040402121','','')
10----------------------------------------------------------------------------------------------------
11UTL_RAW.CAST_TO_VARCHAR2(REPLACE('6F6C61206C61206C61206C61206C61','',''))
12----------------------------------------------------------------------------------------------------
13cieple kluchy, kostuchy @@!!
14ola la la la la

The column 6 (CLOB) on the other hand changes from out of row storage to in-line storage. You can see it by obtaining bytes on position 22 and 23 – "0x4890″ means, that this CLOB is in-line and you can check the actual value by extracting bytes from position 30 to the end.

You can use Python to decode CLOB value. Since my database is AL32UTF8 I have to use utf-16-be coding which is actual coding for CLOBs in Oracle with AL32UTF8.

1>>> print unicode("00 54 00 01 02 0c 80 80 00 02 00 00 00 01 00 00 00 3f 75 b0 00 40 48 90 00 3a 00 00 36 01 00 43 00 7a 00 77 00 61 00 6e 00 65 00 20 00 63 00 7a 01 05 00 73 00 74 00 65 00 63 00 7a 00 6b 00 69 00 20 00 43 00 7a 00 65 00 63 00 68 00 6f 00 77 00 61 00 2e".replace(" ","").decode("hex")[30:],"utf-16-be")
2Czwane cząsteczki Czechowa.

So this is how an UPDATE actually looks like. But the funny thing is, that I found also an INSERT in my REDO dump! It looks like this:

1REDO RECORD - Thread:2 RBA: 0x00009d.00040138.01dc LEN: 0x01f8 VLD: 0x01 CON_UID: 0
2SCN: 0x0000.0160a562 SUBSCN:367 07/24/2017 09:23:05
3CHANGE #1 CON_ID:0 TYP:0 CLS:52 AFN:2 DBA:0x008021b0 OBJ:4294967295 SCN:0x0000.0160a562 SEQ:27 OP:5.1 ENC:0 RBL:0 FLG:0x0000
4ktudb redo: siz: 100 spc: 4054 flg: 0x0022 seq: 0x031e rec: 0x1b
5            xid:  0x0012.016.00001564
6ktubu redo: slt: 22 rci: 26 opc: 11.1 objn: 98618 objd: 98618 tsn: 7
7Undo type:  Regular undo       Undo type:  Last buffer split:  No
8Tablespace Undo:  No
9             0x00000000
10KDO undo record:
11KTB Redo
12op: 0x02  ver: 0x01
13compat bit: 4 (post-11) padding: 1
14op: C  uba: 0x008021af.031e.02
15KDO Op code: DRP row dependencies Disabled
16  xtype: XA flags: 0x00000000  bdba: 0x01c0015f  hdba: 0x01c000b2
17itli: 2  ispac: 0  maxfr: 4858
18tabn: 0 slot: 21(0x15)
19CHANGE #2 CON_ID:0 TYP:0 CLS:1 AFN:7 DBA:0x01c0015f OBJ:98618 SCN:0x0000.0160a562 SEQ:1 OP:11.2 ENC:0 RBL:0 FLG:0x0000
20KTB Redo
21op: 0x02  ver: 0x01
22compat bit: 4 (post-11) padding: 1
23op: C  uba: 0x008021b0.031e.1b
24KDO Op code: IRP row dependencies Disabled
25  xtype: XA flags: 0x00000000  bdba: 0x01c0015f  hdba: 0x01c000b2
26itli: 2  ispac: 24  maxfr: 4858
27tabn: 0 slot: 21(0x15) size/delt: 209
28fb: ----FL-- lb: 0x2  cc: 8
29hrid: 0x01c0015e.20
30null: --------
31col  0: [ 6]  c2 06 01 26 44 3d
32col  1: [15]  6f 6c 61 20 6c 61 20 6c 61 20 6c 61 20 6c 61
33col  2: [11]  78 75 07 18 0b 26 33 1e 84 80 00
34col  3: [11]  78 75 07 18 0b 26 36 05 b8 d8 00
35col  4: [13]  78 75 07 18 0b 26 39 38 25 c7 80 86 38
36col  5: [ 7]  78 75 07 18 0b 27 01
37col  6: [84]
38 00 54 00 01 02 0c 80 80 00 02 00 00 00 01 00 00 00 3f 75 b1 00 40 48 90 00
39 3a 00 00 36 01 00 43 00 7a 00 77 00 61 00 6e 00 65 00 20 00 63 00 7a 01 05
40 00 73 00 74 00 65 00 63 00 7a 00 6b 00 69 00 20 00 43 00 7a 00 65 00 63 00
41 68 00 6f 00 77 00 61 00 2e
42col  7: [45]
43 00 54 00 01 01 0c 00 80 00 01 00 00 00 01 00 00 00 3f 74 2e 00 19 40 90 00
44 13 22 00 10 5b 5d 01 01 02 01 c1 2c c1 6d 02 01 c2 47 f1 18

OP:11.2 is code for INSERT and we can see here all 8 columns of the table. The next REDO record which follows looks almost like a DELETE:

1REDO RECORD - Thread:2 RBA: 0x00009d.000400b5.01a0 LEN: 0x01f8 VLD: 0x01 CON_UID: 0
2SCN: 0x0000.0160a562 SUBSCN:368 07/24/2017 09:23:05
3CHANGE #1 CON_ID:0 TYP:0 CLS:52 AFN:2 DBA:0x008021b0 OBJ:4294967295 SCN:0x0000.0160a562 SEQ:28 OP:5.1 ENC:0 RBL:0 FLG:0x0000
4ktudb redo: siz: 324 spc: 3952 flg: 0x0022 seq: 0x031e rec: 0x1c
5            xid:  0x0012.016.00001564
6ktubu redo: slt: 22 rci: 27 opc: 11.1 objn: 98618 objd: 98618 tsn: 7
7Undo type:  Regular undo       Undo type:  Last buffer split:  No
8Tablespace Undo:  No
9             0x00000000
10KDO undo record:
11KTB Redo
12op: 0x02  ver: 0x01
13compat bit: 4 (post-11) padding: 1
14op: C  uba: 0x008021b0.031e.1a
15KDO Op code: ORP row dependencies Disabled
16  xtype: XA flags: 0x00000000  bdba: 0x01c0015e  hdba: 0x01c000b2
17itli: 2  ispac: 0  maxfr: 4858
18tabn: 0 slot: 32(0x20) size/delt: 172
19fb: --H-FL-- lb: 0x2  cc: 8
20null: --------
21col  0: [ 6]  c2 06 01 26 44 3d
22col  1: [29]
23 63 69 65 70 c5 82 65 20 6b 6c 75 63 68 79 2c 20 6b 6f 73 74 75 63 68 79 20
24 40 40 21 21
25col  2: [11]  78 75 07 18 0b 26 33 1e 84 80 00
26col  3: [11]  78 75 07 18 0b 26 36 05 b8 d8 00
27col  4: [13]  78 75 07 18 0b 26 39 38 25 c7 80 86 38
28col  5: [ 7]  78 75 07 18 0b 27 01
29col  6: [39]
30 00 54 00 01 02 0c 80 80 00 02 00 00 00 01 00 00 00 3f 74 2d 00 13 40 90 00
31 0d 22 00 01 ee c8 01 00 02 01 c0 3a 6b 10
32col  7: [45]
33 00 54 00 01 01 0c 00 80 00 01 00 00 00 01 00 00 00 3f 74 2e 00 19 40 90 00
34 13 22 00 10 5b 5d 01 01 02 01 c1 2c c1 6d 02 01 c2 47 f1 18
35CHANGE #2 CON_ID:0 TYP:0 CLS:1 AFN:7 DBA:0x01c0015e OBJ:98618 SCN:0x0000.0160a562 SEQ:65 OP:11.6 ENC:0 RBL:0 FLG:0x0000
36KTB Redo
37op: 0x02  ver: 0x01
38compat bit: 4 (post-11) padding: 1
39op: C  uba: 0x008021b0.031e.1c
40KDO Op code: ORP row dependencies Disabled
41  xtype: XA flags: 0x00000000  bdba: 0x01c0015e  hdba: 0x01c000b2
42itli: 2  ispac: 0  maxfr: 4858
43tabn: 0 slot: 32(0x20) size/delt: 9
44fb: --H----- lb: 0x2  cc: 0
45nrid:  0x01c0015f.15
46null:

It looks almost like DELETE because the actual DELETE code is 11.3 and not 11.6. So it seems like instead of UPDATE, Oracle is doing an INSERT and then something like DELETE. But why? Everything clears when we ANALYZE a table in search for chained rows.

(Please check out this article by Tanel Poder on chained and migrated rows https://blog.tanelpoder.com/2009/11/04/detect-chained-and-migrated-rows-in-oracle/)

In the UNDO vector, you can see all the values necessary to build an INSERT, which is the actual undo operation for this statement.

Let’s check if the content of the UNDO INSERT matches with a chained row:

1SQL> create table CHAINED_ROWS (
2    owner_name         varchar2(30),
3    table_name         varchar2(30),
4    cluster_name       varchar2(30),
5    partition_name     varchar2(30),
6    subpartition_name  varchar2(30),
7    head_rowid         rowid,
8    analyze_timestamp  date
9  );  2    3    4    5    6    7    8    9
10 
11Table created.
12 
13SQL> analyze table hr.VD_TEST_REPLICATION list chained rows;
14 
15Table analyzed.
16 
17SQL> ed
18Wrote file afiedt.buf
19 
20  1  select t.id
21  2  from hr.VD_TEST_REPLICATION t, CHAINED_ROWS c
22  3  where id=utl_raw.cast_to_number(replace('c2 06 01 26 44 3d',' ',''))
23  4* and   c.head_rowid=t.rowid
24SQL> /
25 
26    ID
27----------
28 500.37676

So we have a winner! Whenever the rows are being chained or migrated, the content of the REDO looks a little bit like INSERT and DELETE instead of just UPDATE.

So it means that chained and migrated rows are not only affecting SELECT statements but also can cause much more REDO to be generated.


Contact us

Database Whisperers sp. z o. o. sp. k.
al. Jerozolimskie 200, 3rd floor, room 342
02-486 Warszawa
NIP: 5272744987
REGON:362524978
+48 508 943 051
+48 661 966 009
info@ora-600.pl

Newsletter Sign up to be updated