Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> RE: log file sync

RE: log file sync

From: <oracle_at_digistar.com>
Date: Fri, 13 Oct 2006 16:43:13 -0400 (EDT)
Message-ID: <Pine.GSO.4.58.0610131608140.23263@digistar.com>

On Fri, 13 Oct 2006, Christian Antognini wrote:

> In your trace file log file sync events are scattered over the whole
> trace file?

hi - no, they are in large blocks through the file. For example there will be sort of like this (values removed to keep the boss happy):

BINDS #13:
 bind 0: dty=1 mxl=32(30) mal=00 scl=00 pre=00 oacflg=01 oacfl2=c000000000000000 size=176 offset=0

   bfp=800003ff7405ff38 bln=32 avl=10 flg=05  bind 1: dty=2 mxl=78(22) mal=00 scl=00 pre=00 oacflg=01 oacfl2=c000000000000000 size=0 offset=32

   bfp=800003ff7405ff58 bln=78 avl=02 flg=01  bind 2: dty=1 mxl=32(30) mal=00 scl=00 pre=00 oacflg=01 oacfl2=c000000000000000 size=0 offset=112

   bfp=800003ff7405ffa8 bln=32 avl=05 flg=01  bind 3: dty=1 mxl=32(30) mal=00 scl=00 pre=00 oacflg=01 oacfl2=c000000000000000 size=0 offset=144

   bfp=800003ff7405ffc8 bln=32 avl=11 flg=01

WAIT #13: nam='db file sequential read' ela= 96 p1=8 p2=143924 p3=1
WAIT #13: nam='log file sync' ela= 6337 p1=3191 p2=0 p3=0
WAIT #13: nam='log file sync' ela= 2101 p1=3386 p2=0 p3=0
WAIT #13: nam='log file sync' ela= 1858 p1=3387 p2=0 p3=0
WAIT #13: nam='log file sync' ela= 955 p1=3388 p2=0 p3=0
... 100+ lines of log file sync
WAIT #13: nam='db file sequential read' ela= 76 p1=79 p2=69671 p3=1
WAIT #13: nam='db file sequential read' ela= 46 p1=78 p2=69819 p3=1
WAIT #13: nam='db file sequential read' ela= 41 p1=78 p2=69823 p3=1
WAIT #13: nam='log file sync' ela= 863 p1=3506 p2=0 p3=0
WAIT #13: nam='db file sequential read' ela= 42 p1=78 p2=69827 p3=1
WAIT #13: nam='db file sequential read' ela= 38 p1=78 p2=69831 p3=1
WAIT #13: nam='db file sequential read' ela= 36 p1=79 p2=69675 p3=1
WAIT #13: nam='db file sequential read' ela= 38 p1=79 p2=69679 p3=1
... a log file sync every 10 db file sequential read then
EXEC #13:c=140000,e=264079,p=76,cr=8750,cu=4739,mis=0,r=56,dep=0,og=4,tim=22023951788104
WAIT #13: nam='SQL*Net message to client' ela= 5 p1=1413697536 p2=1 p3=0
WAIT #13: nam='SQL*Net message from client' ela= 261 p1=1413697536 p2=1 p3=0




The behavior changes but overall it is in this form:

new bind values given (BINDS #13)
a brief sequential read (1 block p3=1)
100+ lines of log file sync
some db file sequential read of 1 block (5-10 lines) a log file sync
some more db file sequential read of 1 block (5-10 lines) a log file sync
... repeat previous 5 lines a few dozen times ... an EXEC
send some sort of acknowledgement to client (p2=1) ? receive some sort of acknowledgement from client (p2=1) ?

This happens nearly 10,000 times.

I did a grep on the tracefile:

Count of BINDS #13 - 9974

Count of 'db file sequential read' - 56882
Count of 'log file sync' - 1564723
Count of 'SQL*Net message to client' - 9978



So I suppose at this point the log file sync may be a product of log_buffer being too large or too small. I have tried large values of 5,000,000 and as small as 320,000. I will try lowering it to 160,000 and re-test.

Any advice or opinions are very welcome... Thanks

--
http://www.freelists.org/webpage/oracle-l
Received on Fri Oct 13 2006 - 15:43:13 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US