Redo Volume Optimization in 12c R2

Posted in: DBA Lounge, Oracle

I was using SLOB to compare the throughput between 12.1 and 12.2 databases, and was surprised to see that the average redo size per transaction was ~18.5KB on 12cR2, and ~339KB on 12cR1. Understanding this difference was important for the assessment and interpretation of the test results.

This is going to be a short blog post about an apparently new redo volume optimization that’s introduced in Oracle Database 12c R2.

Before I explain how I found it, here’s the conclusion for the impatient ones: There’s a new feature in 12cR2 that reduces the redo volume by removing the new column values from the redo records in cases when UPDATES set the column to its already existing value.

I spent some time checking the AWR report differences and tracing the sessions to rule out all the obvious candidates and found nothing obvious there:

  • the redo block size was the same – 512
  • the “redo wastage” (statistic) was very low
  • no other workload was running at the same time, so the transactions were coming purely from SLOB.
  • in both cases, SLOB was configured with the same parameters, and the workload characteristics were the same (i.e. the same number of updates per transaction, the same SQL in the top, etc)

I also used a query I wrote a while ago to extract the redo size (by object and by transaction) directly from the redo logs:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
EXEC DBMS_LOGMNR.ADD_LOGFILE('&FILENAME');
EXEC DBMS_LOGMNR.START_LOGMNR(OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG);
 
SET pages 50000 LINES 500 tab OFF TIME ON serverout ON
col owner FOR a30
col object_name FOR a30
col subobject_name FOR a30
col object_type FOR a30
SELECT * FROM (
SELECT data_obj#,
       owner,
       object_name,
       subobject_name,
       XIDUSN,XIDSLT,XIDSQN,XID,
       COUNT(*)                    REDO_CNT,
       SUM(r_size_b) / 1024 / 1024 REDO_MB
FROM   (SELECT data_obj#,XIDUSN,XIDSLT,XIDSQN,XID,
               rbablk,
               rbabyte,
               rbablk * 512 + rbabyte
                      b_offset,
               ( LEAD(rbablk * 512 + rbabyte)
                   OVER (
                     PARTITION BY rbasqn
                     ORDER BY rbablk*512+rbabyte) ) - ( rbablk * 512 + rbabyte )
                      R_SIZE_B
        FROM   v$logmnr_contents) lc,
       dba_objects o
WHERE  o.object_id(+) = lc.data_obj#
       AND owner='USER1' AND object_name='CF1'GROUP  BY data_obj#,
          owner,
          object_name,
          subobject_name, XIDUSN,XIDSLT,XIDSQN,XID
) WHERE rownum<=5;
 
EXEC DBMS_LOGMNR.END_LOGMNR;

And I confirmed the redo size per transaction was a lot different between the two versions.
This is on 12cR1 (pay attention to the REDO_MB column, I moved it to the front for visibility):

   REDO_MB  DATA_OBJ# OWNER                          OBJECT_NAME                    SUBOBJECT_NAME                     XIDUSN     XIDSLT     XIDSQN XID                REDO_CNT
---------- ---------- ------------------------------ ------------------------------ ------------------------------ ---------- ---------- ---------- ---------------- ----------
.333778381   19726234 USER1                          CF1                                                                    1          0    5582960 0100000070305500         63
.334209442   19726234 USER1                          CF1                                                                    1          0    5582961 0100000071305500         63
.333782196   19726234 USER1                          CF1                                                                    1          1    5583160 0100010038315500         63
 .33380127   19726234 USER1                          CF1                                                                    1          1    5583161 0100010039315500         63
.328651428   19726234 USER1                          CF1                                                                    1          2    5582217 01000200892D5500         63

This is on 12cR2:

   REDO_MB  DATA_OBJ# OWNER                          OBJECT_NAME                    SUBOBJECT_NAME                     XIDUSN     XIDSLT     XIDSQN XID                REDO_CNT
---------- ---------- ------------------------------ ------------------------------ ------------------------------ ---------- ---------- ---------- ---------------- ----------
.018199921     100475 USER1                          CF1                                                                    1          0     148400 01000000B0430200         63
.018596649     100475 USER1                          CF1                                                                    1          0     148351 010000007F430200         63
.018745422     100475 USER1                          CF1                                                                    1          0     148352 0100000080430200         63
.018726349     100475 USER1                          CF1                                                                    1          0     148353 0100000081430200         63
.018543243     100475 USER1                          CF1                                                                    1          0     148354 0100000082430200         63

As I hadn’t observed any workload differences up to this point, I decided to take some logfile dumps and look at them. SLOB uses one SQL statement to update the data, so it was easy to identify the redo records for the CF1:

UPDATE CF1 SET C2 = 'AAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBB', 
               ... skipped 18 more COLUMNS TO improve readability ..., 
               C20 = 'AAAAAAAABBBBBBBBAAAAAAAA0BBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBBBBBBAAAAAAAABBBB0BBBAAAAAAAABBBBBBBBAAAAAAAABBBBB3BBAAAAAAAABBBBBBBB' 
WHERE CUSTID > ( :B1 - :B2 ) AND ( CUSTID < :B1 )

And this is what I found in the redo log dumps on 12cR1 – we see two records per row – redo for the undo blocks first, and the actual change of the CF1, including the new values that the columns are updated to:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
REDO RECORD - Thread:1 RBA: 0x00354d.000002ae.010c LEN: 0x15b0 VLD: 0x01 CON_UID: 0
SCN: 0x0b28.3f9903c6 SUBSCN:  1 06/20/2018 05:41:48
CHANGE #1 CON_ID:0 TYP:0 CLS:83 AFN:7 DBA:0x01c00290 OBJ:4294967295 SCN:0x0b28.3f9903bb SEQ:1 OP:5.2 ENC:0 RBL:0 FLG:0x0000
ktudh redo: slt: 0x0005 sqn: 0x005391cc flg: 0x0012 siz: 2684 fbi: 0
            uba: 0x022173ea.3dc2.02    pxid:  0x0000.000.00000000
CHANGE #2 CON_ID:0 TYP:0 CLS:84 AFN:8 DBA:0x022173ea OBJ:4294967295 SCN:0x0b28.3f9903ba SEQ:2 OP:5.1 ENC:0 RBL:0 FLG:0x0000
ktudb redo: siz: 2684 spc: 5516 flg: 0x0012 seq: 0x3dc2 rec: 0x02
            xid:  0x0022.005.005391cc
ktubl redo: slt: 5 rci: 0 opc: 11.1 [objn: 19726234 objd: 19726236 tsn: 463]
Undo type:  Regular undo        Begin trans    Last buffer split:  No
Temp Object:  No
Tablespace Undo:  No
             0x00000000  prev ctl uba: 0x022173d5.3dc2.02
prev ctl max cmt scn:  0x0b28.3f990377  prev tx cmt scn:  0x0b28.3f990378
txn start scn:  0xffff.ffffffff  logon user: 3124  prev brb: 35746101  prev bcl: 0 BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo
op: 0x04  ver: 0x01
compat bit: 4 (post-11) padding: 1
op: L  itl: xid:  0x0019.016.0055d79e uba: 0x01e5c11c.7646.03
                      flg: C---    lkc:  0     scn: 0x0b28.3f99032b
KDO Op code: URP row dependencies Disabled
  xtype: XA flags: 0x00000000  bdba: 0x0315b558  hdba: 0x02a40003
itli: 2  ispac: 0  maxfr: 4858
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 0 ckix: 6
ncol: 20 nnew: 19 size: 0
col  1: [128] 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42...col 19: [128] 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 30 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 30 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 33 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42CHANGE #3 CON_ID:0 TYP:2 CLS:1 AFN:301 DBA:0x0315b558 OBJ:19726236 SCN:0x0b28.3f990368 SEQ:1 OP:11.5 ENC:0 RBL:0 FLG:0x0000
KTB Redo
op: 0x11  ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F  xid:  0x0022.005.005391cc    uba: 0x022173ea.3dc2.02
Block cleanout record, scn:  0x0b28.3f9903c6 ver: 0x01 opt: 0x02, entries follow...
  itli: 1  flg: (opt=2 whr=1)  scn: 0x0b28.3f990368
KDO Op code: URP row dependencies Disabled
  xtype: XA flags: 0x00000000  bdba: 0x0315b558  hdba: 0x02a40003
itli: 2  ispac: 0  maxfr: 4858
tabn: 0 slot: 0(0x0) flag: 0x2c lock: 2 ckix: 6
ncol: 20 nnew: 19 size: 0
col  1: [128] 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42...col 19: [128] 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 30 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 30 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 33 42 42 41 41 41 41 41 41 41 41 42 42 42 42 42 42 42 42CHANGE #4 MEDIA RECOVERY MARKER CON_ID:0 SCN:0x0000.00000000 SEQ:0 OP:5.20 ENC:0 FLG:0x0000
session number   = 1327
serial  number   = 20241
transaction name =
version 202375680
audit sessionid 931488888
Client Id =
login   username = USER1

However, on 12cR2, the records differ – the new column values are no longer recorded, and I assume it’s because the values actually didn’t change. There are still both redo entries there, but the column values are no longer there:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
REDO RECORD - Thread:1 RBA: 0x00059b.002cd649.016c LEN: 0x0128 VLD: 0x01 CON_UID: 0
SCN: 0x0000000012f55a0f SUBSCN: 59 06/21/2018 07:39:08
CHANGE #1 CON_ID:0 TYP:0 CLS:18 AFN:4 DBA:0x0101a3f6 OBJ:4294967295 SCN:0x0000000012f55a0f SEQ:11 OP:5.1 ENC:0 RBL:0 FLG:0x0000
ktudb redo: siz: 84 spc: 7290 flg: 0x0022 seq: 0x374e rec: 0x0b
        xid:  0x0001.000.000243b0
ktubu redo: slt: 0 rci: 10 opc: 11.1 objn: 100475 objd: 100477 tsn: 7
Undo type:  Regular undo       Undo type:  Last buffer split:  No
Tablespace Undo:  No
         0x00000000
KDO undo record:
KTB Redo
op: 0x04  ver: 0x01
compat bit: 4 (post-11) padding: 1
op: L  itl: xid:  0x0008.000.0002aff4 uba: 0x0101aed8.30cb.4b
                  flg: C---    lkc:  0     scn:  0x0000000012f557ff
KDO Op code: LKR row dependencies Disabled
xtype: XA flags: 0x00000000  bdba: 0x006ee8f5  hdba: 0x00500003
itli: 1  ispac: 0  maxfr: 4858
tabn: 0 slot: 0 to: 0
CHANGE #2 CON_ID:0 TYP:2 CLS:1 AFN:8 DBA:0x006ee8f5 OBJ:100477 SCN:0x0000000012f559d5 SEQ:1 OP:11.4 ENC:0 RBL:0 FLG:0x0000
KTB Redo
op: 0x11  ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F  xid:  0x0001.000.000243b0    uba: 0x0101a3f6.374e.0b
Block cleanout record, scn:  0x0000000012f55a0f ver: 0x01 opt: 0x02 bigscn: Y compact: Y spare: 00000000, entries follow...
itli: 2  flg: (opt=2 whr=1)  scn:  0x0000000012f559d5
KDO Op code: LKR row dependencies Disabled
xtype: XA flags: 0x00000000  bdba: 0x006ee8f5  hdba: 0x00500003
itli: 1  ispac: 0  maxfr: 4858
tabn: 0 slot: 0 to: 1

I haven’t done a very thorough testing, so there may be a situation when it works and when it doesn’t.

email

Interested in working with Maris? Schedule a tech call.

About the Author

Maris Elsins is an experienced Oracle Applications DBA currently working as Lead Database Consultant at The Pythian Group. His main areas of expertise are troubleshooting and performance tuning of Oracle Database and e-Business Suite systems. He is a blogger and a frequent speaker at Oracle related conferences such as UKOUG, Collaborate, Oracle OpenWorld, HotSos, and others. Maris is an Oracle ACE, an Oracle Certified Master, and a co-author of “Practical Oracle Database Appliance” (Apress, 2014). He's also a member of the board at Latvian Oracle User Group.

No comments

Leave a Reply

Your email address will not be published. Required fields are marked *