[Oracle][DATAGUARD] LOGICAL STANDBY环境里，有些SEQUENCE无法应用，导致Primary和Standby无法同期

2022-11-11 10:54:21

今天遇到了一个客户，问题是这样的，客户构筑了一个RACtoRAC的 LOGICAL STANDBY环境。
并用EM在监视同期情况，发现EM页面上55115和55116这两个SEQUENCE一直在应用。

首先向客户要了下列的资料

　Primary端
Script to Collect Data Guard Primary Site Diagnostic Information for Version 10g and Above (Including RAC). (Doc ID 1577401.1)

　Standby端
　　SRDC - Collect Logical Standby Database Information (Doc ID 1910065.1)

=============================
Logical Standby Database (from all Instances if RAC is used)

ALERT.LOG covering at least the Time since the last Instance Startup and the Problem
       Output from Note: 1577407.1 - Script to Collect Data Guard Logical Standby Diagnostic Information for Version 10g and above (Including RAC)
       Output from Note: 1296954.1 - How to monitor the progress of the logical standby
       TNSNAMES.ORA, LISTENER.ORA
       Latest LSPx- and ASxx-Tracefiles from Background Dump-Directory
=============================

拿到资料后，先看Standby端的DB alert log

1. 是不是Redo没有传到Standby端

[root@standby ~]# grep 'RFS LogMiner: Registered logfile.*thread_1' alert_mykartes.log　★从Standby端抽取传输信息
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55109.346.955743463] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55110.347.955743463] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55108.351.955743463] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55112.338.955743463] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55111.339.955743463] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55113.340.955743463] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55114.354.955743503] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55115.361.955744421] to LogMiner session id [2]
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567] to LogMiner session id [2]　★55116之后的数字也出现了
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55117.391.955749633] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55118.393.955749695] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55119.399.955750553] to LogMiner session id [2]　★RFS进程接收REDO看起来很正常
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55120.406.955751745] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55121.415.955753049] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55122.422.955754083] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55123.428.955755081] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55124.439.955756675] to LogMiner session id [2]　★
RFS LogMiner: Registered logfile [+DG1/mykartes/foreign_archivelog/mykarte/2017_09_27/thread_1_seq_55125.442.955756975] to LogMiner session id [2]

2. 55115和55116，这两个SEQUENCE应用出了什么错么

[root@yan1 ~]# grep 'LOGMINER: Begin mining logfile for session 2 thread 1 sequence 5511' alert_mykartes.log
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55110, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55110.347.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55111, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55111.339.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55112, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55112.338.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55113, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55113.340.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55114, +DG1/mykartes/onlinelog/group_10.315.955743237
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55115, +DG1/mykartes/onlinelog/group_9.314.955743237
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55116, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55111, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55111.339.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55112, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55112.338.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55113, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55113.340.955743463
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55114, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55114.354.955743503
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55115, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55115.361.955744421　★55115
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55116, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567　★55116
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55115, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55115.361.955744421　★55115
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55116, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567　★55116
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55115, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55115.361.955744421　★55115
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55116, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567　★55116
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55115, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55115.361.955744421　★55115
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55116, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567　★55116
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55115, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55115.361.955744421　★55115
LOGMINER: Begin mining logfile for session 2 thread 1 sequence 55116, +DG1/mykartes/foreign_archivelog/mykarte/2017_09_26/thread_1_seq_55116.373.955746567　★55116

我了个去，为啥这两个SEQUENCE会应用这么多次！
看起来好像是LSP进程一直想要应用他们，但就是应用不了。

那就只能从 Doc ID 1910065.1 的资料里找线索了。

Doc ID 1910065.1 的脚本执行结果被客户放在了 new_dg_lsby_diag_mykartes_20170928_1729.html 里面

3.Check 一下REDO的应用状况

new_dg_lsby_diag_mykartes_20170928_1729.html 的部分信息
===========================
SQL> SELECT thread#, sequence#, first_change#, next_change#, dict_begin beg, dict_end end, TO_CHAR(timestamp, 'hh:mi:ss') timestamp, (CASE WHEN l.next_change# < p.read_scn THEN 'YES' WHEN l.first_change# < p.applied_scn THEN 'CURRENT' ELSE 'NO' END) applied FROM dba_logstdby_log l, dba_logstdby_progress p ORDER BY thread#, first_change#;

THREAD# SEQUENCE# FIRST_CHANGE# NEXT_CHANGE# BEG END TIMESTAM APPLIED
1 55107 3734503196 3734503595 NO NO 08:17:43 YES
1 55108 3734503595 3734504891 YES NO 08:17:43 YES
1 55109 3734504891 3734506783 NO YES 08:17:43 YES
1 55110 3734506783 3734506876 NO NO 08:17:43 YES
1 55111 3734506876 3734507595 NO NO 08:17:43 YES
1 55112 3734507595 3734508534 NO NO 08:17:43 YES
1 55113 3734508534 3734509236 NO NO 08:17:43 YES
1 55114 3734509236 3734509452 NO NO 08:18:22 YES
1 55115 3734509452 3734532403 NO NO 08:33:41 CURRENT　★55115在应用中
1 55116 3734532403 3734613007 NO NO 09:09:27 CURRENT　★55116在应用中
1 55117 3734613007 3734706486 NO NO 10:00:32 NO
1 55118 3734706486 3734805339 NO NO 10:01:35 NO
===========================

有戏啊，看来就是这两个家伙的应用hang了。

4.Check 一下REDO应用时有没有什么Error

new_dg_lsby_diag_mykartes_20170928_1729.html により抜粋
===========================
SQL> -- Verify that log apply services on the standby are currently running.　★
SQL> -- If the query against V$LOGSTDBY returns no rows then logical apply is not running.
SQL>
SQL> column status format a50 wrap
SQL> column type format a11
SQL> set numwidth 15
SQL>
SQL> SELECT type, status, high_scn FROM v$logstdby;

TYPE STATUS HIGH_SCN
COORDINATOR ORA-16116: 使用できる作業はありません 3734535493
ANALYZER ORA-16116: 使用できる作業はありません 3734559504
APPLIER ORA-16113: 表またはシーケンス"SYS"."AUD$"に変更を 適用しています 3734535506　★ORA-16113
APPLIER ORA-16113: 表またはシーケンス"SYS"."AUD$"に変更を 適用しています 3734535504　★ORA-16113
APPLIER ORA-16113: 表またはシーケンス"SYS"."AUD$"に変更を 適用しています 3734535499　★ORA-16113
APPLIER ORA-16113: 表またはシーケンス"SYS"."AUD$"に変更を 適用しています 3734535494　★ORA-16113
APPLIER ORA-16113: 表またはシーケンス"SYS"."AUD$"に変更を 適用しています 3734535511　★ORA-16113
READER ORA-16127: 追加のトランザクションが適用されるまで 待機して停止しました。 3734560999
BUILDER ORA-16127: 追加のトランザクションが適用されるまで 待機して停止しました。 3734559504
PREPARER ORA-16127: 追加のトランザクションが適用されるまで 待機して停止しました。 3734559503
===========================

丁……
好多ORA-16113啊！

5.从MOS寻找关于ORA-16113的文档

[参考情報]

　ORA-16113: applying change to table or sequence "SYS"."AUD$" (Doc ID 1964125.1)

===========================
Symptoms　★事象

Archives stoped applying on logical standby server

Checking apply with this query we find it is stuck on the SYS.AUD$ table
SELECT type, status, high_scn FROM v$logstdby;

TYPE STATUS HIGH_SCN
COORDINATOR ORA-16116: no work available 4157595068
ANALYZER ORA-16116: no work available 4157607708
APPLIER ORA-16123: transaction 22 31 76123 is waiting for commit approval 4157595083
APPLIER ORA-16123: transaction 8 25 71375 is waiting for c ommit approval 4157595075
APPLIER ORA-16123: transaction 2 27 68682 is waiting for c ommit approval 4157595077
APPLIER ORA-16113: applying change to table or sequence "SYS"."AUD$"　★很像啊
＜省略＞
Cause　★原因

Although SYS is an INTERNAL SCHEMA there are some objects that are propagated to the logical standby because they support user data.
These are some: AUD$, SEQ$, and FGA$
What usually happens is the SYS.AUD$ table gets too big and then it is too slow to be updated in the logical standby.　★SYS.AUD$ table肥大化的话，就有可能发生哦
You can skip the object or reorg it in the primary.

Solution　★解決方法
＜省略＞
If not using broker
ALTER DATABASE STOP LOGICAL STANDBY APPLY;　★

SQL> exec dbms_logstdby.skip('DML','SYS','AUD$');　★
SQL> exec dbms_logstdby.skip('SCHEMA_DDL','SYS','AUD$');　★

ALTER DATABASE START LOGICAL STANDBY APPLY IMMEDIATE;　★
===========================
 
这不就是她嘛！！！！

让客户实验了一下上面的解决方法，客户的现象就解决了。

LOGICAL STANDBY的CASE已经不多，客户更多的还是使用PHYSICAL STANDBY。
遇到LOGICAL STANDBY的时候发现，可以参照下面的MOS文档，个人感觉很有帮助。

Troubleshooting Logical Standby (Doc ID 215020.1)

上一篇：使用Office 365 试用账户 体验Office 365功能


下一篇：JavaSE 字符串和正则表达式