log file sync waits / slow response time at log switches

  • From: "Gerald Cunningham" <gcunningham@xxxxxxxxxxxxxxxxxxxxxxxx>
  • To: <oracle-l@xxxxxxxxxxxxx>
  • Date: Thu, 14 Feb 2008 14:21:45 -0500

Hi all,
 
My 10046 tracing is showing a lot of "log file sync" waits. Also, users log 
files (processes are doing DML) are showing 
spikes in response time that match the times of the log switches.
 
This is a physical Data Guard implementation with 1 primary / 1 standby. Oracle 
9.2.0.8 64-bit on Solaris.
 
From the alert log, it appears that Oracle is waiting until the redo 
information has been written to the standby site 
before it switches the primary's redo logs.
 
log_archive_dest_3 was set to mandatory, so I tried setting it to optional (see 
line "c" below). This didn't appear to 
have any effect. Here is an excerpt of my primary alert log:
 
===
(a) Thu Feb 14 17:39:23 2008
    LGWR: Completed archiving  log 2 thread 1 sequence 155723
    Creating archive destination LOG_ARCHIVE_DEST_3: 'STDBY_DG'
    LNS0 started with pid=249, OS id=9556
(b) Thu Feb 14 17:39:32 2008
    LGWR: Beginning to archive log 3 thread 1 sequence 155724
    Thread 1 advanced to log sequence 155274
      Current log# 3 seq# 155724 mem# 0: /dbdata_11/oradata/prod/redo03_1.log
      Current log# 3 seq# 155724 mem# 1: /dbdata_12/oradata/prod/redo03_2.log
    Thu Feb 14 17:39:32 2008
    ARC1: Evaluating archive   log 2 thread 1 sequence 155723
    ARC1: Archive destination LOG_ARCHIVE_DEST_3: Previously completed
    ARC1: Beginning to archive log 2 thread 1 sequence 155723
    Creating archive destination LOG_ARCHIVE_DEST_2: 
'/dbdata_15/oradata/prod/ARCHIVE/arch_1_155723.arc'
    Creating archive destination LOG_ARCHIVE_DEST_1: 
'/dbdata_10/oradata/prod/ARCHIVE/arch_1_155723.arc'
    Thu Feb 14 17:39:45 2008
    ARC1: Completed archiving  log 2 thread 1 sequence 155723
    Thu Feb 14 17:41:45 2008
(c) ALTER SYSTEM SET log_archive_dest_3='service=STDBY_DG LGWR ASYNC=20480 
AFFIRM OPTIONAL REOPEN=30' SCOPE=MEMORY;
(d) Thu Feb 14 17:43:17 2008
    LGWR: Completed archiving  log 3 thread 1 sequence 155724
    Creating archive destination LOG_ARCHIVE_DEST_3: 'STDBY_DG'
    LNS0 started with pid=221, OS id=12045
(e) Thu Feb 14 17:43:35 2008
    LGWR: Beginning to archive log 1 thread 1 sequence 155725
    Thread 1 advanced to log sequence 155275
      Current log# 1 seq# 155725 mem# 0: /dbdata_16/oradata/prod/redo01_1.log
      Current log# 1 seq# 155725 mem# 1: /dbdata_17/oradata/prod/redo01_2.log
===
Questions:
 
- I believe the time from a-to-b and d-to-e is where my users are waiting, 
because Oracle hasn't switched the redo log 
yet. Is this true? These 2 waits are 9 seconds and 18 seconds! Sometimes they 
are longer, or shorter, but this is typical.
 
- I thought when I changed dest_3 to optional, Oracle would switch the 
local/primary first, then do the "standby stuff". 
Why isn't it?
 
- Is the time from a-to-b and c-to-d for creating the new LNS0 process? If so, 
is there any way to have a persistent LNS0 process?
 
- Is there any way to force the local/primary redo to switch *before* doing any 
standby work?
 

Thanks very much for any help!
 
Jerry

Other related posts: