TAGGED POSTS / logdump

logdump output errors for tables with ROWDEPENDENCIES

Every Oracle database user assumes that the output of the logdump command should provide a valid output.

During testing of OpenLogReplicator I came across something strange. It appears that the output of OpenLogReplicator logdump mode is better than the original output of Oracle database logdump command.

Maybe I am wrong?

Let’s create a test scenario for 3 tables:

create table usr1.adam1(
  a numeric,
  b number(10),
  c number(10, 2),
  d char(10),
  e varchar2(10),
  f timestamp,
  g date
);
create table usr1.adam2(
  a numeric,
  b number(10),
  c number(10, 2),
  d char(10),
  e varchar2(10),
  f timestamp, g date
) rowdependencies;
create table usr1.adam3(
  a numeric,
  b number(10),
  c number(10, 2),
  d char(10),
  e varchar2(10),
  f timestamp,
  g date
);

Let’s create a test scenario:

insert into USR1.ADAM3 values(100, 999, 10.22, 'xxx', 'yyy', to_date('2019-08-01 12:34:56', 'YYYY-MM-DD HH24:MI:SS'), null);
insert into USR1.ADAM3 values(101, 999, 10.22, 'xxx', 'yyy', to_date('2019-08-01 12:34:56', 'YYYY-MM-DD HH24:MI:SS'), null);
insert into USR1.ADAM3 values(102, 999, 10.22, 'xxx', 'yyy', to_date('2019-08-01 12:34:56', 'YYYY-MM-DD HH24:MI:SS'), null);
insert into USR1.ADAM3 values(103, 999, 10.22, 'xxx', 'yyy', to_date('2019-08-01 12:34:56', 'YYYY-MM-DD HH24:MI:SS'), null);
insert into USR1.ADAM3 values(104, 999, 10.22, 'xxx', 'yyy', to_date('2019-08-01 12:34:56', 'YYYY-MM-DD HH24:MI:SS'), null);
commit;
insert into USR1.ADAM1 select * from USR1.ADAM3;
insert into USR1.ADAM2 select * from USR1.ADAM3;
commit;

The most important 2 last INSERT operations. Let’s focus on those. Since the table has 5 rows the INSERT would not use the OP:11.2 (INSERT) operation but OP:11.11 (QMI) instead. This is a Quick Massive Insert.

Let’s look at logdump for the inserts to the table without ROWDEPENDENCIES. It looks quite nice:

CHANGE #3 CON_ID:0 TYP:0 CLS:1 AFN:4 DBA:0x0100008c OBJ:41377 SCN:0x0000000000f8d6bf SEQ:2 OP:11.11 ENC:0 RBL:0 FLG:0x0000
KTB Redo 
op: 0x01  ver: 0x01  
compat bit: 4 (post-11) padding: 1
op: F  xid:  0x0008.01d.000032f8    uba: 0x00c01ff0.08c8.23
KDO Op code: QMI row dependencies Disabled
  xtype: XA flags: 0x00000000  bdba: 0x0100008c  hdba: 0x0100008a
itli: 1  ispac: 0  maxfr: 4858
tabn: 0 lock: 1 nrow: 5
slot[0]: 0
tl: 37 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 2]  c2 02
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[1]: 1
tl: 38 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 02
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[2]: 2
tl: 38 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 03
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[3]: 3
tl: 38 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 04
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[4]: 4
tl: 38 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 05
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39

OpenLogReplicator displays the same output but additionally provides HEX dump of the Redo Vector:

##: 32
##   0:  0b 0b 01 00 04 00 00 00  8c 00 00 01 bf d6 f8 00 
##  10:  00 00 00 00 02 00 a1 a1  00 00 00 00 00 00 00 00 
##: 24 (1)
##   0:  01 0d 00 00 00 00 00 00  08 00 1d 00 f8 32 00 00 
##  10:  f0 1f c0 00 c8 08 23 00 
##: 32 (2)
##   0:  8c 00 00 01 8a 00 00 01  fa 12 0b 01 01 00 00 00 
##  10:  00 01 05 00 00 00 01 00  02 00 03 00 04 00 00 00 
##: 10 (3)
##   0:  25 00 26 00 26 00 26 00  26 00 
##: 189 (4)
##   0:  2c 00 06 02 c2 02 03 c2  0a 64 03 c1 0b 17 0a 78 
##  10:  78 78 20 20 20 20 20 20  20 03 79 79 79 07 78 77 
##  20:  08 01 0d 23 39 2c 00 06  03 c2 02 02 03 c2 0a 64 
##  30:  03 c1 0b 17 0a 78 78 78  20 20 20 20 20 20 20 03 
##  40:  79 79 79 07 78 77 08 01  0d 23 39 2c 00 06 03 c2 
##  50:  02 03 03 c2 0a 64 03 c1  0b 17 0a 78 78 78 20 20 
##  60:  20 20 20 20 20 03 79 79  79 07 78 77 08 01 0d 23 
##  70:  39 2c 00 06 03 c2 02 04  03 c2 0a 64 03 c1 0b 17 
##  80:  0a 78 78 78 20 20 20 20  20 20 20 03 79 79 79 07 
##  90:  78 77 08 01 0d 23 39 2c  00 06 03 c2 02 05 03 c2 
##  a0:  0a 64 03 c1 0b 17 0a 78  78 78 20 20 20 20 20 20 
##  b0:  20 03 79 79 79 07 78 77  08 01 0d 23 39 

And then let’s look to the inserts to the table with ROWDEPENDENCIES?

CHANGE #2 CON_ID:0 TYP:0 CLS:1 AFN:4 DBA:0x01000094 OBJ:41378 SCN:0x0000000000f8d6c7 SEQ:2 OP:11.11 ENC:0 RBL:0 FLG:0x0000
KTB Redo 
op: 0x01  ver: 0x01  
compat bit: 4 (post-11) padding: 1
op: F  xid:  0x0008.01d.000032f8    uba: 0x00c01ff0.08c8.24
KDO Op code: QMI row dependencies Enabled
  xtype: XA flags: 0x00000004  bdba: 0x01000094  hdba: 0x01000092
itli: 1  ispac: 0  maxfr: 4858
tabn: 0 lock: 1 nrow: 5
slot[0]: 0
tl: 183 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [0]
col  1: [128]
 00 00 00 00 00 00 02 c2 02 03 c2 0a 64 03 c1 0b 17 0a 78 78 78 20 20 20 20
 20 20 20 03 79 79 79 07 78 77 08 01 0d 23 39 2c
dmp lmt after 41
col  2: [ 1] 
dmp lmt after 0
col  3: [35]
dmp lmt after 0
col  4: [ 3] 
dmp lmt after 0
col  5: [ 7] 
dmp lmt after 0
slot[1]: 1
tl: 298 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [0]
col  1: [128]
 00 00 00 00 00 00 03 c2 02 02 03 c2 0a 64 03 c1 0b 17 0a 78 78 78 20 20 20
 20 20 20 20 03 79 79 79 07 78 77 08 01 0d 23 39 2c
dmp lmt after 42
col  2: [ 8] 
dmp lmt after 0
col  3: [128]
dmp lmt after 0
col  4: [23]
dmp lmt after 0
col  5: [ 2] 
dmp lmt after 0
slot[2]: 2
tl: 145 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [0]
col  1: [128]
 00 00 00 00 00 00 03 c2 02 03 03 c2 0a 64 03 c1 0b 17 0a 78 78 78 20 20 20
 20 20 20 20 03 79 79 79 07 78 77 08 01 0d 23 39 2c
dmp lmt after 42
col  2: [ 8] 
dmp lmt after 0
col  3: [0]
col  4: [0]
col  5: [0]
slot[3]: 3
tl: 330 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [0]
col  1: [128]
 00 00 00 00 00 00 03 c2 02 04 03 c2 0a 64 03 c1 0b 17 0a 78 78 78 20 20 20
 20 20 20 20 03 79 79 79 07 78 77 08 01 0d 23 39 2c
dmp lmt after 42
col  2: [0]
col  3: [0]
col  4: [193]
dmp lmt after 0
col  5: *NULL*
slot[4]: 4
tl: 162 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [0]
col  1: [128]
 00 00 00 00 00 00 03 c2 02 05 03 c2 0a 64 03 c1 0b 17 0a 78 78 78 20 20 20
 20 20 20 20 03 79 79 79 07 78 77 08 01 0d 23 39 00
dmp lmt after 42
col  2: [23]
dmp lmt after 0
col  3: [ 2] 
dmp lmt after 0
col  4: [0]
col  5: [0]

As you can see the output is some random data.

And let’s look at the output of OpenLogReplicator working with logdump mode with HEX dump above:

CHANGE #2 CON_ID:0 TYP:0 CLS:1 AFN:4 DBA:0x01000094 OBJ:41378 SCN:0x0000000000f8d6c7 SEQ:2 OP:11.11 ENC:0 RBL:0 FLG:0x0000
##: 32
##   0:  0b 0b 01 00 04 00 00 00  94 00 00 01 c7 d6 f8 00 
##  10:  00 00 00 00 02 00 a2 a1  00 00 00 00 00 00 00 00 
##: 24 (1)
##   0:  01 0d 00 00 00 00 00 00  08 00 1d 00 f8 32 00 00 
##  10:  f0 1f c0 00 c8 08 24 00 
##: 32 (2)
##   0:  94 00 00 01 92 00 00 01  fa 12 4b 05 01 00 00 00 
##  10:  00 01 05 00 00 00 01 00  02 00 03 00 04 00 00 00 
##: 10 (3)
##   0:  2d 00 2e 00 2e 00 2e 00  2e 00 
##: 229 (4)
##   0:  2c 00 06 00 80 00 00 00  00 00 00 02 c2 02 03 c2 
##  10:  0a 64 03 c1 0b 17 0a 78  78 78 20 20 20 20 20 20 
##  20:  20 03 79 79 79 07 78 77  08 01 0d 23 39 2c 00 06 
##  30:  00 80 00 00 00 00 00 00  03 c2 02 02 03 c2 0a 64 
##  40:  03 c1 0b 17 0a 78 78 78  20 20 20 20 20 20 20 03 
##  50:  79 79 79 07 78 77 08 01  0d 23 39 2c 00 06 00 80 
##  60:  00 00 00 00 00 00 03 c2  02 03 03 c2 0a 64 03 c1 
##  70:  0b 17 0a 78 78 78 20 20  20 20 20 20 20 03 79 79 
##  80:  79 07 78 77 08 01 0d 23  39 2c 00 06 00 80 00 00 
##  90:  00 00 00 00 03 c2 02 04  03 c2 0a 64 03 c1 0b 17 
##  a0:  0a 78 78 78 20 20 20 20  20 20 20 03 79 79 79 07 
##  b0:  78 77 08 01 0d 23 39 2c  00 06 00 80 00 00 00 00 
##  c0:  00 00 03 c2 02 05 03 c2  0a 64 03 c1 0b 17 0a 78 
##  d0:  78 78 20 20 20 20 20 20  20 03 79 79 79 07 78 77 
##  e0:  08 01 0d 23 39 
KTB Redo 
op: 0x01  ver: 0x01  
compat bit: 4 (post-11) padding: 1
op: F  xid:  0x0008.01d.000032f8    uba: 0x00c01ff0.08c8.24
KDO Op code: QMI row dependencies Enabled
  xtype: XA flags: 0x00000004  bdba: 0x01000094  hdba: 0x01000092
itli: 1  ispac: 0  maxfr: 4858
tabn: 0 lock: 1 nrow: 5
slot[0]: 0
tl: 45 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 2]  c2 02
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[1]: 1
tl: 46 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 02
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[2]: 2
tl: 46 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 03
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[3]: 3
tl: 46 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 04
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39
slot[4]: 4
tl: 46 fb: --H-FL-- lb: 0x0  cc: 6
col  0: [ 3]  c2 02 05
col  1: [ 3]  c2 0a 64
col  2: [ 3]  c1 0b 17
col  3: [10]  78 78 78 20 20 20 20 20 20 20
col  4: [ 3]  79 79 79
col  5: [ 7]  78 77 08 01 0d 23 39

I don’t have to put many arguments on the table to prove that OpenLogReplicator’s interpretation is closer is more convincing. Since we insert the same data to ADAM1 and ADAM2 the logdump command should display a similar output. As you can clearly see the output for a table with ROWDEPENDENCIES is somewhat random. Here is side-by side comparison:

output screen showing errors in output of logdump command and the correct interpretation produced by OpenLogReplicator

I have observed this error in all database versions: 11.2.0.4, 12.1.0.2, 12.2.0.1, 18.9.0.0, 19.6.0.0 with newest patch sets, so… my guess is that Oracle company knows about them but apparently there was no business case to fix it 😉

Happy logdumping with OpenLogReplicator

OpenLogReplicator – logdump functionality

A side product of OpenLogReplicator is the ability to create logs which are in a very simular form as the logdump command from Oracle database.

To create such dump you need to configure parameter in the OpenLogReplicator CFG file.

"dumplogfile": "2",

There are 2 allowed values:

  1. create classic ‘logdump’ output
  2. create classic ‘logdump’ output enhanced with interpretation of additional fields for which logdump does not print any information – like supplemental log data

You can also configure a second parameter:

"dumpdata": "1",

This parameter would cause to add a binary dump of the redo log vector before the text interpretation of the data. Here is an example of the output – the binary log has been highlighted with reverse colors:

logdump output from OpenLogReplicator

For every redo log file OpenLogReplicator would create a separate logdump-alike dump named DUMP-xxx.trace where xxx is the redo log sequence number.

Of course OpenLogReplicator displays interpretation for very few Op codes – which itself would be able to analyze and use for CDC replication. In next versions the list of supported Op codes may increase.

loading
×