LGWR writes

From: Gaja Krishna Vaidyanatha <gajav_at_yahoo.com>
Date: Mon, 18 Dec 2000 22:03:38 -0800 (PST)
Message-Id: <10714.124898@fatcity.com>

Greetings,

Last week we discussed about various issues related to LGWR and one of them was the debate over the 1/3rd full event writes. Although it has been re-verified that the code does indicate - MIN(1 Mb., log_buffer/3), the working of the 1/3 event is still in question.

After further detailed checking, discussing with the concerened individuals and performing some tests, here is what we have. Attached is the information.

Best Regards,

Gaja

Gaja,

I finally got a consensus on the copy latches as shown below. We do take out "a redo copy latch" to write the log buffer to the log file.

In versions prior to 8i, LGWR had to get and release all redo copy latches (in wait mode) to ensure no foreground processes were changing redo buffers it was about to write.

In 8i, it still has to check if any foreground processes are copying redo into buffers it wants to write, but it does it in the following way:

Each copy latch stores the lowest redo block address that is being copied by the foreground process holding the latch.
When foreground processes are finished copying they set the value of the redo block address stored in the latch to a very high value (max value).
LGWR will look at the redo block value for EACH COPY latch to see if it is within its range of blocks it wants to write.
If LGWR finds a copy latch associated with a block it wants to write, LGWR will try a nowait latch get on the latch just in case the process that was holding it, died.
If the nowait failed (someone still holding the latch and copying) then LGWR asks to be posted by the foreground when the latch is released.
Once it is posted and sees the copy is finished, it will proceed to the next copy latch until all of them have been checked.
After all copy latches are checked it will proceed to write the buffers out to the log.

The code does show MIN - my mistake when I wrote the note to you. But I think that this one-third full does not work as advertised.

I created a 3 meg log buffer - note from the dump below that it is using 512 byte blocks so my redo buffer contains 6144 blocks. My logfiles are 6 meg in size. I set event 10046 level 12 for the LGWR process and looked for the number of blocks written at one time (this is wait event 'log file parallel write' and the number of blocks written is shown in p2) and found that it wrote anywhere from a few blocks up to 4133 (which is two thirds of the redo buffer) blocks at a time.

There were no commits in the test and there was significant redo generated within 3 sec intervals.

LOGFILE DUMP
Mon Dec 18 15:23:33 2000
ORACLE V8.1.6.0.0 - Production vsnsta=0 vsnsql=e vsnxtr=3
Windows NT Version 4.0 Service Pack 5, CPU type 586 Oracle8i Enterprise Edition Release 8.1.6.0.0 - Production With the Partitioning option
JServer Release 8.1.6.0.0 - Production
Windows NT Version 4.0 Service Pack 5, CPU type 586 Instance name: d816

Redo thread mounted by this instance: 1

Oracle process number: 14

Windows thread id: 299, image: ORACLE.EXE

2000-12-18 15:23:33.468
SESSION ID:(11.3) 2000-12-18 15:23:33.390

DUMP OF REDO FROM FILE 'F:\ORANT816\ORADATA\D816\REDO07.LOG' Opcodes *.*
DBA's: (file # 0, block # 0) thru (file # 2000000, block # 4194303)
RBA's: 0x000000.00000000.0000 thru 0xffffffff.ffffffff.ffff SCN's scn: 0x0000.00000000 thru scn: 0xffff.ffffffff Times: creation thru eternity
FILE HEADER:
Software vsn=135290880=0x8106000, Compatibility Vsn=135290880=0x8106000
Db Id=1921075784=0x72814a48, Db Name='D816' Control Seq=4203=0x106b, File size=12288=0x3000

File Number=6, Blksiz=512, File Type=2 LOG <<--Note for Blksiz

descrip:"Thread 0001, Seq# 0000001266, SCN 0x000000234800-0xffffffffffff"
thread: 1 nab: 0xffffffff seq: 0x4f2 eot: 1 dis: 0 reset logs count: 0x1781bb48 Reset scn: 0x0000.00000001 Low scn: 0x0000.00234800 12/18/2000 15:22:53 Next scn: 0xffff.ffffffff 01/01/1988 00:00:00 END OF REDO DUMP The following trace file on LGWR has been edited to remove all idle-events such as rdbms ipc message.

TRACE FILE FOR LGWR USING EVENT 10046 LEVEL 12

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=2076 p3=2

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=16 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=748 p3=1

WAIT #0: nam='latch free' ela= 0 p1=19827448 p2=74 p3=0

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=1329 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=748 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=1327 p3=2

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=750 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=1318 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=754 p3=1

...
WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=364 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=1718 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=581 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=1503 p3=2

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=1499 p3=1

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=4337 p3=3

Note the "wait for the redo copy latch" below when the system switched logfiles:

WAIT #0: nam='log file single write' ela= 0 p1=0 p2=1 p3=1 WAIT #0: nam='control file sequential read' ela= 0 p1=0 p2=7 p3=1

WAIT #0: nam='log file sequential read' ela= 0 p1=0 p2=1 p3=1 
WAIT #0: nam='log file single write' ela= 0 p1=0 p2=1 p3=1 
WAIT #0: nam='control file parallel write' ela= 0 p1=3 p2=3 p3=3

WAIT #0: nam='control file sequential read' ela= 0 p1=0 p2=85 p3=1
WAIT #0: nam='control file parallel write' ela= 0 p1=3 p2=3 p3=3

WAIT #0: nam='control file sequential read' ela= 0 p1=0 p2=6 p3=1
WAIT #0: nam='control file parallel write' ela= 0 p1=3 p2=3 p3=3

WAIT #0: nam='control file parallel write' ela= 0 p1=3 p2=3 p3=3

WAIT #0: nam='control file sequential read' ela= 0 p1=0 p2=8 p3=1
WAIT #0: nam='control file sequential read' ela= 0 p1=0 p2=23 p3=1
WAIT #0: nam='file identify' ela= 0 p1=0 p2=0 p3=0 WAIT #0: nam='file open' ela= 0 p1=0 p2=0 p3=0

WAIT #0: nam='LGWR wait for redo copy' ela= 0 p1=0 p2=0 p3=0

WAIT #0: nam='log file parallel write' ela= 0 p1=1 p2=326 p3=1

Gaja Krishna Vaidyanatha
Director, Storage Management Products, Quest Software Inc. Office : (972)-304-1170, E-mail : gaja_at_quest.com

Author:Oracle Performance Tuning 101 by Osborne McGraw-Hill "Opinions and views expressed are my own and not of Quest" Received on Tue Dec 19 2000 - 00:03:38 CST