Re: Question about redo size in dump file and view

From: <stevedhoward_at_gmail.com>
Date: Sun, 7 Jun 2009 09:38:24 -0700 (PDT)
Message-ID: <1febac6b-f3de-4dce-ac75-0d3d37891769_at_g20g2000vba.googlegroups.com>



On Jun 7, 7:41 am, lsllcm <lsl..._at_gmail.com> wrote:
> Below are dump file of redo log
>
> Trace file c:\app\lcm\diag\rdbms\orcl\orcl\trace\orcl_ora_4176.trc
> Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - Production
> With the Partitioning, OLAP, Data Mining and Real Application Testing
> options
> Windows NT Version V6.0 Service Pack 1
> CPU : 2 - type 586, 2 Physical Cores
> Process Affinity : 0x00000000
> Memory (Avail/Total): Ph:823M/1991M, Ph+PgF:2250M/4225M, VA:1417M/
> 2047M
> Instance name: orcl
> Redo thread mounted by this instance: 1
> Oracle process number: 34
> Windows thread id: 4176, image: ORACLE.EXE (SHAD)
>
> *** 2009-06-07 19:00:03.892
> *** SESSION ID:(129.65) 2009-06-07 19:00:03.892
> *** CLIENT ID:() 2009-06-07 19:00:03.892
> *** SERVICE NAME:(orcl) 2009-06-07 19:00:03.892
> *** MODULE NAME:(PL/SQL Developer) 2009-06-07 19:00:03.892
> *** ACTION NAME:(命令窗口 - 新建) 2009-06-07 19:00:03.892
>
> DUMP OF REDO FROM FILE 'C:\APP\LCM\ORADATA\ORCL\REDO01.LOG'
> Opcodes 19.*
> RBAs: 0x000000.00000000.0000 thru 0xffffffff.ffffffff.ffff
> SCNs: scn: 0x0000.00000000 thru scn: 0xffff.ffffffff
> Times: creation thru eternity
> FILE HEADER:
> Compatibility Vsn = 185597952=0xb100000
> Db ID=1212237983=0x4841489f, Db Name='ORCL'
> Activation ID=1212213407=0x4840e89f
> Control Seq=6636=0x19ec, File size=102400=0x19000
> File Number=1, Blksiz=512, File Type=2 LOG
> descrip:"Thread 0001, Seq# 0000000322, SCN
> 0x0000004cdff2-0x0000004cdff9"
> thread: 1 nab: 0x5 seq: 0x00000142 hws: 0x2 eot: 0 dis: 0
> resetlogs count: 0x28cbfd1f scn: 0x0000.00000001 (1)
> prev resetlogs count: 0x0 scn: 0x0000.00000000
> Low scn: 0x0000.004cdff2 (5038066) 06/07/2009 18:59:49
> Next scn: 0x0000.004cdff9 (5038073) 06/07/2009 18:59:50
> Enabled scn: 0x0000.00000001 (1) 04/17/2009 23:00:55
> Thread closed scn: 0x0000.004cdff2 (5038066) 06/07/2009 18:59:49
> Disk cksum: 0xcb15 Calc cksum: 0xcb15
> Terminal recovery stop scn: 0x0000.00000000
> Terminal recovery 01/01/1988 00:00:00
> Most recent redo scn: 0x0000.00000000
> Largest LWN: 2 blocks
> End-of-redo stream : No
> Unprotected mode
> Miscellaneous flags: 0x0
> Thread internal enable indicator: thr: 0, seq: 0 scn: 0x0000.00000000
> END OF REDO DUMP
> ----- Redo read statistics for thread 1 -----
> Read rate (ASYNC): 1Kb in 0.03s => 0.05 Mb/sec
> Total redo bytes: 1Kb Longest record: 0Kb, moves: 0/2 moved: 0Mb (0%)
> Longest LWN: 1Kb, reads: 2
> Last redo scn: 0x0000.004cdff6 (5038070)
> Change vector header moves = 0/8 (0%)
> ----------------------------------------------
>
> *** 2009-06-07 19:00:11.612
>
> DUMP OF REDO FROM FILE 'C:\APP\LCM\ORADATA\ORCL\REDO01.LOG'
> Opcodes *.*
> RBAs: 0x000000.00000000.0000 thru 0xffffffff.ffffffff.ffff
> SCNs: scn: 0x0000.00000000 thru scn: 0xffff.ffffffff
> Times: creation thru eternity
> FILE HEADER:
> Compatibility Vsn = 185597952=0xb100000
> Db ID=1212237983=0x4841489f, Db Name='ORCL'
> Activation ID=1212213407=0x4840e89f
> Control Seq=6636=0x19ec, File size=102400=0x19000
> File Number=1, Blksiz=512, File Type=2 LOG
> descrip:"Thread 0001, Seq# 0000000322, SCN
> 0x0000004cdff2-0x0000004cdff9"
> thread: 1 nab: 0x5 seq: 0x00000142 hws: 0x2 eot: 0 dis: 0
> resetlogs count: 0x28cbfd1f scn: 0x0000.00000001 (1)
> prev resetlogs count: 0x0 scn: 0x0000.00000000
> Low scn: 0x0000.004cdff2 (5038066) 06/07/2009 18:59:49
> Next scn: 0x0000.004cdff9 (5038073) 06/07/2009 18:59:50
> Enabled scn: 0x0000.00000001 (1) 04/17/2009 23:00:55
> Thread closed scn: 0x0000.004cdff2 (5038066) 06/07/2009 18:59:49
> Disk cksum: 0xcb15 Calc cksum: 0xcb15
> Terminal recovery stop scn: 0x0000.00000000
> Terminal recovery 01/01/1988 00:00:00
> Most recent redo scn: 0x0000.00000000
> Largest LWN: 2 blocks
> End-of-redo stream : No
> Unprotected mode
> Miscellaneous flags: 0x0
> Thread internal enable indicator: thr: 0, seq: 0 scn: 0x0000.00000000
>
> REDO RECORD - Thread:1 RBA: 0x000142.00000002.0010 LEN: 0x01e8 VLD:
> 0x0d
> SCN: 0x0000.004cdff3 SUBSCN: 1 06/07/2009 18:59:50
> CHANGE #1 TYP:2 CLS: 1 AFN:4 DBA:0x0100090f OBJ:70582 SCN:
> 0x0000.004ba463 SEQ: 1 OP:11.2
> KTB Redo
> op: 0x01 ver: 0x01
> compat bit: 4 (post-11) padding: 0
> op: F xid: 0x0005.01f.00000655 uba: 0x00c00529.02c8.05
> KDO Op code: IRP row dependencies Disabled
> xtype: XA flags: 0x00000000 bdba: 0x0100090f hdba: 0x0100090b
> itli: 2 ispac: 0 maxfr: 4858
> tabn: 0 slot: 1(0x1) size/delt: 6
> fb: --H-FL-- lb: 0x2 cc: 1
> null: -
> col 0: [ 2] c1 02
> CHANGE #2 TYP:0 CLS:25 AFN:3 DBA:0x00c00049 OBJ:4294967295 SCN:
> 0x0000.004cdfd7 SEQ: 2 OP:5.2
> ktudh redo: slt: 0x001f sqn: 0x00000655 flg: 0x0012 siz: 132 fbi: 0
> uba: 0x00c00529.02c8.05 pxid: 0x0000.000.00000000
> CHANGE #3 TYP:0 CLS:25 AFN:3 DBA:0x00c00049 OBJ:4294967295 SCN:
> 0x0000.004cdff3 SEQ: 1 OP:5.4
> ktucm redo: slt: 0x001f sqn: 0x00000655 srt: 0 sta: 9 flg: 0x2 ktucf
> redo: uba: 0x00c00529.02c8.05 ext: 3 spc: 6344 fbi: 0
> CHANGE #4 TYP:0 CLS:26 AFN:3 DBA:0x00c00529 OBJ:4294967295 SCN:
> 0x0000.004cdfd7 SEQ: 1 OP:5.1
> ktudb redo: siz: 132 spc: 6478 flg: 0x0012 seq: 0x02c8 rec: 0x05
> xid: 0x0005.01f.00000655
> ktubl redo: slt: 31 rci: 0 opc: 11.1 objn: 70582 objd: 70582 tsn: 4
> Undo type: Regular undo Begin trans Last buffer split: No
> Temp Object: No
> Tablespace Undo: No
> 0x00000000 prev ctl uba: 0x00c00529.02c8.04
> prev ctl max cmt scn: 0x0000.004cdacc prev tx cmt scn:
> 0x0000.004cdaed
> txn start scn: 0x0000.004cdc64 logon user: 0 prev brb: 12584231
> prev bcl: 0 BuExt idx: 0 flg2: 0
> KDO undo record:
> KTB Redo
> op: 0x04 ver: 0x01
> compat bit: 4 (post-11) padding: 0
> op: L itl: xid: 0x0008.01c.0000069d uba: 0x00c00b21.0292.12
> flg: C--- lkc: 0 scn: 0x0000.004ba45f
> KDO Op code: DRP row dependencies Disabled
> xtype: XA flags: 0x00000000 bdba: 0x0100090f hdba: 0x0100090b
> itli: 2 ispac: 0 maxfr: 4858
> tabn: 0 slot: 1(0x1)
>
> REDO RECORD - Thread:1 RBA: 0x000142.00000003.0010 LEN: 0x0254 VLD:
> 0x0d
> SCN: 0x0000.004cdff6 SUBSCN: 1 06/07/2009 18:59:50
> CHANGE #1 TYP:2 CLS: 1 AFN:4 DBA:0x0100090f OBJ:70582 SCN:
> 0x0000.004cdff3 SEQ: 2 OP:11.19
> KTB Redo
> op: 0x11 ver: 0x01
> compat bit: 4 (post-11) padding: 0
> op: F xid: 0x0002.008.0000066b uba: 0x00c011ed.0282.2a
> Block cleanout record, scn: 0x0000.004cdff5 ver: 0x01 opt: 0x02,
> entries follow...
> itli: 1 flg: 2 scn: 0x0000.004ba463
> itli: 2 flg: 2 scn: 0x0000.004cdff3
> Array Update of 1 rows:
> tabn: 0 slot: 1(0x1) flag: 0x2c lock: 1 ckix: 0
> ncol: 1 nnew: 1 size: 0
> KDO Op code: 21 row dependencies Disabled
> xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x0100090f hdba:
> 0x0100090b
> itli: 1 ispac: 0 maxfr: 4858
> vect = 0
> col 0: [ 2] c1 03
> CHANGE #2 TYP:0 CLS:19 AFN:3 DBA:0x00c00019 OBJ:4294967295 SCN:
> 0x0000.004cdfd9 SEQ: 2 OP:5.2
> ktudh redo: slt: 0x0008 sqn: 0x0000066b flg: 0x0012 siz: 180 fbi: 0
> uba: 0x00c011ed.0282.2a pxid: 0x0000.000.00000000
> CHANGE #3 TYP:0 CLS:19 AFN:3 DBA:0x00c00019 OBJ:4294967295 SCN:
> 0x0000.004cdff6 SEQ: 1 OP:5.4
> ktucm redo: slt: 0x0008 sqn: 0x0000066b srt: 0 sta: 9 flg: 0x2 ktucf
> redo: uba: 0x00c011ed.0282.2a ext: 2 spc: 2474 fbi: 0
> CHANGE #4 TYP:0 CLS:20 AFN:3 DBA:0x00c011ed OBJ:4294967295 SCN:
> 0x0000.004cdfd9 SEQ: 1 OP:5.1
> ktudb redo: siz: 180 spc: 2656 flg: 0x0012 seq: 0x0282 rec: 0x2a
> xid: 0x0002.008.0000066b
> ktubl redo: slt: 8 rci: 0 opc: 11.1 objn: 70582 objd: 70582 tsn: 4
> Undo type: Regular undo Begin trans Last buffer split: No
> Temp Object: No
> Tablespace Undo: No
> 0x00000000 prev ctl uba: 0x00c011ed.0282.29
> prev ctl max cmt scn: 0x0000.004cdabf prev tx cmt scn:
> 0x0000.004cdaeb
> txn start scn: 0x0000.004cdff3 logon user: 0 prev brb: 12587497
> prev bcl: 0 BuExt idx: 0 flg2: 0
> KDO undo record:
> KTB Redo
> op: 0x04 ver: 0x01
> compat bit: 4 (post-11) padding: 0
> op: L itl: xid: 0x0005.003.00000642 uba: 0x00c00895.02c7.01
> flg: C--- lkc: 0 scn: 0x0000.004ba463
> Array Update of 1 rows:
> tabn: 0 slot: 1(0x1) flag: 0x2c lock: 0 ckix: 0
> ncol: 1 nnew: 1 size: 0
> KDO Op code: 21 row dependencies Disabled
> xtype: XAxtype KDO_KDOM2 flags: 0x00000080 bdba: 0x0100090f hdba:
> 0x0100090b
> itli: 1 ispac: 0 maxfr: 4858
> vect = 0
> col 0: [ 2] c1 02
> END OF REDO DUMP
> ----- Redo read statistics for thread 1 -----
> Read rate (ASYNC): 1Kb in 0.02s => 0.07 Mb/sec
> Total redo bytes: 1Kb Longest record: 0Kb, moves: 0/2 moved: 0Mb (0%)
> Longest LWN: 1Kb, reads: 2
> Last redo scn: 0x0000.004cdff6 (5038070)
> Change vector header moves = 0/8 (0%)
> ----------------------------------------------

I honestly have no clue, but I can say the a redo record is made up of multiple change vectors. The fourth change in the redo record you posted has the following...

CHANGE #4 TYP:0 CLS:26 AFN:3 DBA:0x00c00529 OBJ:4294967295 SCN: 0x0000.004cdfd7 SEQ: 1 OP:5.1
ktudb redo: siz: 132 spc: 6478 flg: 0x0012 seq: 0x02c8 rec: 0x05

            xid: 0x0005.01f.00000655

132 is much closer to 140 than 488 is, so I bet the other 350 or so odd bytes have to do with "recursive" redo (things not performed by your change, but occurred as a result of, like undo). That is just a guess though, and would be curious as to what the ultimate answer is.

BTW, what Oracle version and OS platform?

Regards,

Steve Received on Sun Jun 07 2009 - 11:38:24 CDT

Original text of this message