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 39OpenLogReplicator 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 39I 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:
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