This discussion is archived
10 Replies Latest reply: Sep 17, 2012 5:37 AM by ray_h RSS

Redo not being applied, Transport/Apply Lag grows

ray_h Newbie
Currently Being Moderated
Hello all.

Running Oracle 11.2.0.2 on Linux (64 bit)

I've a problem with Data Guard, and can't see where I've gone wrong.

PRIMARY = bvlive
PHYSICAL STANDBY = bvstby

Replicated bvstby from bvlive, set up the DG broker, and all's well. But wait, a minute or two later, I can see that
the Transport and Apply Lag start to increase.

Tried creating a table on the primary, it doesn't get to the standby.
Checked the SCN on both databases and they're different.

So, redo isn't being applied. However, if I issue a:
ALTER SYSTEM ARCHIVE LOG CURRENT;
from the Primary, the standby gets updated - only for the lag to return.

Looking at the alert log for the Standby - I can see that it gets stuck at:
Media Recovery Waiting for thread 1 sequence 100 (in transit)
but before this, there's this clue:
RFS[2]: No standby redo logfiles available for thread 1
but there are no error messages to support this.

and also:
SELECT SEQUENCE#,FIRST_TIME, NEXT_TIME, APPLIED FROM V$ARCHIVED_LOG ORDER BY SEQUENCE#;
shows that everything has been applied:
 SEQUENCE# FIRST_TIM NEXT_TIME APPLIED  
---------- --------- --------- ---------
        87 13-SEP-12 13-SEP-12 YES
        88 13-SEP-12 13-SEP-12 YES
        89 13-SEP-12 13-SEP-12 YES
        90 13-SEP-12 13-SEP-12 YES
        91 13-SEP-12 13-SEP-12 YES
        92 13-SEP-12 13-SEP-12 YES
        93 13-SEP-12 13-SEP-12 YES
        94 13-SEP-12 13-SEP-12 YES
        95 13-SEP-12 13-SEP-12 YES
        96 13-SEP-12 13-SEP-12 YES
        97 13-SEP-12 13-SEP-12 YES
        98 13-SEP-12 13-SEP-12 YES
        99 13-SEP-12 13-SEP-12 YES
Yet the lag just grows and grows.

Here are the parameters of interest:

Primary:
<font color="red">
*.db_file_name_convert='bvstby','bvlive'
*.db_name='bvlive'
*.db_unique_name='bvlive'
*.fal_server='bvlive'
*.log_archive_config='dg_config=(bvlive,bvstby)'
*.log_archive_dest_1='location=USE_DB_RECOVERY_FILE_DEST valid_for=(all_logfiles,all_roles ) db_unique_name=bvlive'
*.log_archive_dest_2='service=bvstby async valid_for=(online_logfiles,primary_role) db_unique_name=bvstby'
*.log_archive_dest_state_1='ENABLE'
*.log_archive_dest_state_2='ENABLE'
*.log_file_name_convert='bvstby','bvlive'
*.standby_file_management='AUTO'
</font>


Standby:
<font color="blue">
*.db_file_name_convert='bvlive','bvstby'
*.db_name='bvlive'
*.db_unique_name='bvstby'
*.fal_client='bvstby'
*.fal_server='bvlive'
*.log_archive_config='dg_config=(bvlive,bvstby)'
*.log_archive_dest_1='location=USE_DB_RECOVERY_FILE_DEST','valid_for=(ALL_LOGFILES, ALL_ROLES) db_unique_name=bvstby'
*.log_archive_dest_state_1='ENABLE'
*.log_archive_dest_state_2='ENABLE'
*.log_archive_dest_state_3='ENABLE'
*.log_file_name_convert='bvlive','bvstby'
*.standby_file_management='AUTO'
</font>

I'm guessing it's something very obvious, but I've looked around and not seen anything which can shed light on this. The absence of an error message in the alert log doesn't help.

Has anyone encountered this before? Ideas/comments gratefully recieved.

Thanks,
Ray
  • 1. Re: Redo not being applied, Transport/Apply Lag grows
    mseberg Guru
    Currently Being Moderated
    Can you run this and post the results?

    http://www.visi.com/~mseberg/monitor_data_guard_transport.html

    This message

    Media Recovery Waiting for thread 1 sequence 100 (in transit)

    Normal no issue

    This message

    RFS[2]: No standby redo logfiles available for thread 1

    Warning, I'd probably add SRL but Data Guard will still work.

    * Not seeing any lag*

    Standby Redo Log will buffer and prevent lag

    You can use a query like this on your standby to measure apply rates
    set linesize 400
    col Values for a65
    col Recover_start for a21
    select 
      to_char(START_TIME,'dd.mm.yyyy hh24:mi:ss') "Recover_start",
      to_char(item)||' = '||to_char(sofar)||' '||to_char(units)||' '|| to_char(TIMESTAMP,'dd.mm.yyyy hh24:mi') "Values" 
    from 
      v$recovery_progress 
    where 
      start_time=(select max(start_time) from v$recovery_progress);
    Example return from mine
    Recover_start         Values
    --------------------- -----------------------------------------------------------------
    15.06.2012 05:40:51   Log Files = 1704 Files
    15.06.2012 05:40:51   Active Apply Rate = 17677 KB/sec
    15.06.2012 05:40:51   Average Apply Rate = 17 KB/sec
    15.06.2012 05:40:51   Maximum Apply Rate = 48353 KB/sec
    15.06.2012 05:40:51   Redo Applied = 134013 Megabytes
    15.06.2012 05:40:51   Last Applied Redo = 0 SCN+Time 13.09.2012 12:08
    15.06.2012 05:40:51   Active Time = 8181 Seconds
    15.06.2012 05:40:51   Apply Time per Log = 4 Seconds
    15.06.2012 05:40:51   Checkpoint Time per Log = 0 Seconds
    15.06.2012 05:40:51   Elapsed Time = 7799081 Seconds
    Best Regards

    mseberg

    Edited by: mseberg on Sep 13, 2012 1:12 PM
  • 2. Re: Redo not being applied, Transport/Apply Lag grows
    CKPT Guru
    Currently Being Moderated
    RFS[2]: No standby redo logfiles available for thread 1
    This clue is enough..
    Where is your standby redo log files?
    How many standby log files you created?
    What is your protection mode?

    Ensure you have created extra 1 set of redo log group more than Online redo log files.
    have you started MRP with Real time apply?

    You are using Broker, so stop and start MRP once as below.

    DGMGRL> EDIT DATABASE 'standby_db_unique_name' SET STATE='APPLY-OFF';
    DGMGRL> EDIT DATABASE 'standby_db_unique_name' SET STATE='APPLY-ON';

    And then also check for any network issues.

    Thanks
  • 3. Re: Redo not being applied, Transport/Apply Lag grows
    CKPT Guru
    Currently Being Moderated
    RFS[2]: No standby redo logfiles available for thread 1
    This clue is enough..
    Where is your standby redo log files?
    How many standby log files you created?
    What is your protection mode?

    Ensure you have created extra 1 set of redo log group more than Online redo log files.
    have you started MRP with Real time apply?

    You are using Broker, so stop and start MRP once as below.

    DGMGRL> EDIT DATABASE 'standby_db_unique_name' SET STATE='APPLY-OFF';
    DGMGRL> EDIT DATABASE 'standby_db_unique_name' SET STATE='APPLY-ON';

    And then also check for any network issues.

    Thanks
  • 4. Re: Redo not being applied, Transport/Apply Lag grows
    ray_h Newbie
    Currently Being Moderated
    Hello there; thanks for looking at this.

    @mseberg - your query returned the following:
    DB_NAME    HOSTNAME       LOG_ARCHIVED LOG_APPLIED APPLIED_TIME   LOG_GAP 
    ---------- -------------- ------------ ----------- -------------- -------
    BVLIVE     DR-ORA2B                 98          99 13-SEP/17:20        -1
    I'm a bit curious about the log_gap being -1 - what does that mean?

    The apply rates look like this:
    Recover_start         Values                                                                    
    --------------------- ----------------------------------------------------------------- 
    13.09.2012 17:19:41   Log Files = 2 Files0x5172f205 dest 2:
    13.09.2012 17:19:41   Average Apply Rate = 59 KB/sec
    13.09.2012 17:19:41   Redo Applied = 2 Megabytes
    13.09.2012 17:19:41   Last Applied Redo = 0 SCN+Time 13.09.2012 17:19
    13.09.2012 17:19:41   Elapsed Time = 1 Seconds                
    @CKPT:
    I can see in my recovery destination that no archivelogs have been created today!
    We're in MAXPERFORMANCE Mode.

    Stopped and restarted MRP as suggested - doesn't make a difference. The only thing thats seems to work is a log switch.
  • 5. Re: Redo not being applied, Transport/Apply Lag grows
    mseberg Guru
    Currently Being Moderated
    Ray;

    I'm thinking you have rebuilt your standby and the -1 comes from the prior standby. If not something is wrong because the Standby cannot be ahead of the Primary and that what this shows.

    Can you do 2 or 3 log switches and run it again? Posting the results

    Best Regards

    mseberg
  • 6. Re: Redo not being applied, Transport/Apply Lag grows
    CKPT Guru
    Currently Being Moderated
    @CKPT:
    I can see in my recovery destination that no archivelogs have been created today!
    We're in MAXPERFORMANCE Mode.

    Stopped and restarted MRP as suggested - doesn't make a difference. The only thing thats seems to work is a log switch.
    If its applying by performing logswitch, then it mean its not real-time apply. It may be because of insufficient number of redo log groups (or) insufficient standby redo log file size.
    Consider below two things.

    1) if your Online redo log group members are 10, Then create same number or 11 standby redo log file groups in standby.
    2) If your Online redo log members each size is 500mb, Ensure you have same size of standby redo log files.

    Check using below queries and post output.


    From Primary:-
    SQL> select group#,type from v$logfile order by type;
    SQL> select group#,bytes/1024/1024 from v$log;
    SQL> show parameter log_archive_dest_2


    From Standby:-
    SQL> SELECT * FROM V$STANDBY_EVENT_HISTOGRAM WHERE NAME = 'apply lag' AND COUNT > 0;
    SQL> select group#,bytes/1024/1024 from v$standby_log;
  • 7. Re: Redo not being applied, Transport/Apply Lag grows
    ray_h Newbie
    Currently Being Moderated
    Performed a few log switches, the results of your query (on standby) are below:
    DB_NAME    HOSTNAME       LOG_ARCHIVED LOG_APPLIED APPLIED_TIME   LOG_GAP 
    ---------- -------------- ------------ ----------- -------------- -------
    BVLIVE     DR-ORA2B                 98         102 17-SEP/10:17        -4
    I can see that archivelogs aren't being created on the primary unless I issue a log switch.

    @mseberg: your suggestion seems correct. Here are archivelog files created on the primary today (following a switch):
    ./  ../  o1_mf_1_101_85fxx7gg_.arc  o1_mf_1_102_85fy6cy8_.arc
    but on standby:
    ./  ../  o1_mf_1_102_85fxx7jt_.arc  *o1_mf_1_103_85fy6d2l_.arc*
    standby is ahead of the primary! But I've checked the parameters a dozen times and they look sane to me.

    @CKPT:
    PRIMARY:
    
    SQL> select group#,type from v$logfile order by type;
    
        GROUP# TYPE
    ---------- -------
             4 ONLINE
             4 ONLINE
             3 ONLINE
             3 ONLINE
             2 ONLINE
             1 ONLINE
             2 ONLINE
             1 ONLINE
             5 STANDBY                                                                         
             5 STANDBY     
    
    SQL> select group#,bytes/1024/1024 from v$log;
    
        GROUP# BYTES/1024/1024
    ---------- ---------------
             1            1280
             2            1280
             3            1280
             4            1280     
    
    show parameter log_archive_dest_2
    
    NAME                                 TYPE        VALUE
    ------------------------------------ ----------- ------------------------------
    log_archive_dest_2                   string      service=bvstby async valid_for
                                                     =(online_logfiles,primary_role
                                                     ) db_unique_name=bvstby 
    
    
    STANDBY:
    
    SQL> SELECT * FROM V$STANDBY_EVENT_HISTOGRAM WHERE NAME = 'apply lag' AND COUNT > 0 order by last_time_updated;                                    
    
    NAME                                                                   TIME UNIT                  COUNT LAST_TIME_UPDATED
    ---------------------------------------------------------------- ---------- ---------------- ---------- --------------------
    apply lag                                                                 5 hours                  2696 09/14/2012 11:44:19
    apply lag                                                                 6 hours                  3596 09/14/2012 12:44:19
    apply lag                                                                 7 hours                  3595 09/14/2012 13:44:18
    apply lag                                                                 8 hours                  3596 09/14/2012 14:44:19
    apply lag                                                                 9 hours                  3596 09/14/2012 15:44:20
    apply lag                                                                10 hours                  3595 09/14/2012 16:44:19
    apply lag                                                                11 hours                  3596 09/14/2012 17:44:19
    apply lag                                                                15 hours                  3595 09/14/2012 21:44:18
    apply lag                                                                16 hours                  3596 09/14/2012 22:44:19
    apply lag                                                                17 hours                  3597 09/14/2012 23:44:19
    apply lag                                                                18 hours                  3596 09/15/2012 00:44:19
    apply lag                                                                19 hours                  3596 09/15/2012 01:44:19
    apply lag                                                                20 hours                  3595 09/15/2012 02:44:19
    apply lag                                                                21 hours                  3596 09/15/2012 03:44:19
    apply lag                                                                22 hours                  3598 09/15/2012 04:44:21
    apply lag                                                                23 hours                  3594 09/15/2012 05:44:19
    apply lag                                                                 1 days                   3596 09/15/2012 06:44:19
    apply lag                                                                 4 days                  12501 09/17/2012 10:12:54
    apply lag                                                                 3 days                  86306 09/17/2012 10:13:07
    apply lag                                                                 2 days                  86298 09/17/2012 10:13:13
    apply lag                                                                14 hours                  3620 09/17/2012 10:13:15
    apply lag                                                                12 hours                  3699 09/17/2012 10:15:00
    apply lag                                                                13 hours                  3765 09/17/2012 10:17:48
    apply lag                                                                31 seconds                   1 09/17/2012 10:17:49
    apply lag                                                                32 seconds                   2 09/17/2012 10:18:19
    apply lag                                                                33 seconds                   2 09/17/2012 10:18:20
    apply lag                                                                34 seconds                   2 09/17/2012 10:18:21
    apply lag                                                                35 seconds                   2 09/17/2012 10:18:22
    apply lag                                                                36 seconds                   2 09/17/2012 10:18:23
    apply lag                                                                37 seconds                   2 09/17/2012 10:18:24
    apply lag                                                                38 seconds                   2 09/17/2012 10:18:25
    apply lag                                                                39 seconds                   2 09/17/2012 10:18:26
    apply lag                                                                40 seconds                   2 09/17/2012 10:18:27
    apply lag                                                                41 seconds                   2 09/17/2012 10:18:28
    apply lag                                                                42 seconds                   2 09/17/2012 10:18:29
    apply lag                                                                43 seconds                   2 09/17/2012 10:18:30
    apply lag                                                                44 seconds                   2 09/17/2012 10:18:31
    apply lag                                                                45 seconds                   2 09/17/2012 10:18:32
    apply lag                                                                46 seconds                   2 09/17/2012 10:18:33
    apply lag                                                                47 seconds                   2 09/17/2012 10:18:34
    apply lag                                                                48 seconds                   2 09/17/2012 10:18:35
    apply lag                                                                49 seconds                   2 09/17/2012 10:18:36
    apply lag                                                                50 seconds                   2 09/17/2012 10:18:37
    apply lag                                                                51 seconds                   2 09/17/2012 10:18:38
    apply lag                                                                 5 minutes                  60 09/17/2012 10:22:46
    apply lag                                                                 6 minutes                  60 09/17/2012 10:23:46
    apply lag                                                                 7 minutes                  60 09/17/2012 10:24:46
    apply lag                                                                 8 minutes                  60 09/17/2012 10:25:46
    apply lag                                                                 9 minutes                  60 09/17/2012 10:26:46
    apply lag                                                                10 minutes                  60 09/17/2012 10:27:46
    apply lag                                                                11 minutes                  60 09/17/2012 10:28:46
    apply lag                                                                12 minutes                  60 09/17/2012 10:29:46
    apply lag                                                                13 minutes                  60 09/17/2012 10:30:46
    apply lag                                                                14 minutes                  60 09/17/2012 10:31:46
    apply lag                                                                15 minutes                  60 09/17/2012 10:32:46
    apply lag                                                                16 minutes                  60 09/17/2012 10:33:46
    apply lag                                                                17 minutes                  59 09/17/2012 10:34:45
    apply lag                                                                18 minutes                  60 09/17/2012 10:35:46
    apply lag                                                                19 minutes                  59 09/17/2012 10:36:45
    apply lag                                                                20 minutes                  60 09/17/2012 10:37:45
    apply lag                                                                21 minutes                  61 09/17/2012 10:38:46
    apply lag                                                                22 minutes                  60 09/17/2012 10:39:46
    apply lag                                                                23 minutes                  60 09/17/2012 10:40:46
    apply lag                                                                24 minutes                  60 09/17/2012 10:41:46
    apply lag                                                                25 minutes                  60 09/17/2012 10:42:46
    apply lag                                                                26 minutes                  60 09/17/2012 10:43:46
    apply lag                                                                27 minutes                  38 09/17/2012 10:44:24                  
    
    
    SQL> select group#,bytes/1024/1024 from v$standby_log;
    
        GROUP# BYTES/1024/1024
    ---------- ---------------
             5             100
  • 8. Re: Redo not being applied, Transport/Apply Lag grows
    mseberg Guru
    Currently Being Moderated
    Hello Ray;

    OK, you sold me. Please create the missing SRL on the standby.

    Create Missing Standby Redo logs :

    http://www.visi.com/~mseberg/create_missing_standby_redo_logs.html


    Best Regards

    mseberg
  • 9. Re: Redo not being applied, Transport/Apply Lag grows
    Shivananda Rao Guru
    Currently Being Moderated
    Standby:

    SQL> select group#,bytes/1024/1024 from v$standby_log;

    GROUP# BYTES/1024/1024
    ---------- ---------------
    5 100
    Hi,

    It looks like you are having only 1 Standby Redo Log (SRL) Group and 4 Online Redo Log Groups. Please make sure that the number of SRL groups are equal or one more in number to that of the Online Redo Log Groups. ( atleast 5 SRL groups on the standby & primary)
  • 10. Re: Redo not being applied, Transport/Apply Lag grows
    ray_h Newbie
    Currently Being Moderated
    Created the missing groups and it works perfectly.

    Many thanks to you all for replying.

    Ray

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points