Oracle Goldengate ERROR OGG 00446 解决方法

阅读量：5759 次

发布时间：2019-06-18

本文共 8927 字，大约阅读时间需要 29 分钟。

一、问题描述：

2013年4月14日中午12点左右生产环境执行数据库版本升级期间根据需要停止XX1库和XX2库OGG 同步抽取进程时遇长事务，无法用正常命令停止，执行 forcestop 后重启进程报 OGG-00446 错误，无法启动。错误如下：

2013-04-14 19:30:28 ERROR OGG-00446 Opening ASM file+FRA/bjschxsb/1_7125_796652962.dbf in DBLOGREADER mode: (308) ORA-00308: ca

nnot open archived log'+FRA/bjschxsb/1_7125_796652962.dbf'

ORA-17503: ksfdopn:2 Failed toopen file +FRA/bjschxsb/1_7125_796652962.dbf

ORA-15173: entry'1_7125_796652962.dbf' does not exist in directory 'bjschxsb'

Not able to establish initialposition for sequence 7125, rba 339291664.

2013-04-14 19:30:28 ERROR OGG-01668 PROCESS ABENDING.

二、问题原因：

XX1库和XX2库的 Extract 进程在执行 forcestop 停止前（瞬间）正在处理既未提交也未回滚的长时间运行事务，重新启动 Extract 进程后需要执行 Extract 进程恢复。

1、XX1库

停止XX1库Extract 进程时，正在处理的长事务为：

2013-04-1411:51:46 WARNING OGG-01027 Oracle GoldenGate Capture for Oracle,esb_cx7.prm: Long Running Transaction:XID 561.10.312

84,Items 0, Extract ESB_CX7, Redo Thread 1, SCN 3098.1568409621 (13307377092629),Redo Seq #7125, Redo RBA 339291664.

截止目前该事务在数据库中仍在进行：

SQL> select t.addr,t.XIDUSN,t.XIDSLOT,t.XIDSQN,t.START_DATEfrom gv$transaction t;

ADDR XIDUSN XIDSLOT XIDSQN START_DATE

---------------- ---------- ---------- ----------------------------

070000084724BB90 561 10 31284 09-APR-13

SQL> select t.PREV_SQL_ID,t.SQL_ID from gv$session t wheretaddr='070000084724BB90';

PREV_SQL_ID SQL_ID

------------- -------------

9m7787camwh4m

SQL> select sql_text from gv$sqltext t where t.SQL_ID = '9m7787camwh4m';

SQL_TEXT

----------------------------------------------------------------

begin :id := sys.dbms_transaction.local_transaction_id; end;

该事务是由一台 IP 地址为 162.16.220.70 的机器，通过 PL/SQL dev 工具于 2013 年 4 月 9 日发起，使用数据库用户是HX_SJZ，该事务至今未提交也未回滚。需要注意的是 HX_SJZ 用户权限已于 2013 年

4 月 1日开始收回，该主机使用该用户从 3 月 28 日用该用户建立的 session 至今未断开。

selectt.SID,t.SERIAL#,t.SCHEMA#,t.SCHEMANAME,t.OSUSER,t.MACHINE,t.PORT,t.TERMINAL,t.PROGRAMfrom gv$session t where taddr='070000084724BB90';

SID SERIAL# SCHEMA# SCHEMANAMEOSUSER MACHINE PORT TERMINAL PROGRAM

---------- -------------------- ---------- ---------- -------------------- ---------- ----------------------------------------

3351 107 77 HX_SJZ css5 WORKGROUP\CSS-PC 53796CSS-PC plsqldev.exe

bjschxdbsb01:/u01/app/grid/diag/tnslsnr/bjschxdbsb01/listener/trace$catlistener.log | grep css5 | grep162.16.220.70 > /home/grid/listener.bak_20130414

qldev.exe)(HOST=CSS-PC)(USER=css5)))* (ADDRESS=(PROTOCOL=tcp)(HOST=162.16.220.70)(PORT=53313)) * establish *bjschxsb * 0

28-MAR-2013 23:26:06 *(CONNECT_DATA=(SERVICE_NAME=bjschxsb)(GLOBAL_NAME=bjschxsb)(CID=(PROGRAM=D:\Program?Files\PLSQL?Developer\plsqldev.exe)(HOST=CSS-PC)(USER=css5)))* (ADDRESS=(PROTOCOL=tcp)(HOST=162.16.220.70)(PORT=53796)) * establish *bjschxsb * 0

28-MAR-2013 23:34:51 *(CONNECT_DATA=(SERVICE_NAME=bjschxsb)(GLOBAL_NAME=bjschxsb)(CID=(PROGRAM=D:\Program?Files\PLSQL?Developer\plsqldev.exe)(HOST=CSS-PC)(USER=css5)))* (ADDRESS=(PROTOCOL=tcp)(HOST=162.16.220.70)(PORT=53920)) * establish *bjschxsb * 0

28-MAR-2013 23:36:37 *(CONNECT_DATA=(SERVICE_NAME=bjschxsb)(GLOBAL_NAME=bjschxsb)(CID=(PROGRAM=D:\Program?Files\PLSQL?Developer\plsqldev.exe)(HOST=CSS-PC)(USER=css5)))* (ADDRESS=(PROTOCOL=tcp)(HOST=162.16.220.70)(PORT=53944)) * establish *bjschxsb * 0

重启XX1库上的 Extract进程后，需要使用thread 1, seq 7125-7152 归档日志，而 seq 7125 归档正好已被删除，这就是报错的原因。

Recovery Checkpoint (position of oldestunprocessed transaction in the data source):

Thread #: 1

Sequence #: 7125

RBA: 339291664

Timestamp: 2013-04-09 15:18:13.000000

SCN: 3098.1568409621 (13307377092629)

Redo File: Not Available

Current Checkpoint (position of last recordread in the data source):

Thread #: 1

Sequence #: 7152

RBA: 253142788

Timestamp: 2013-04-14 11:59:29.000000

SCN: 3099.705644312 (13310809294616)

Redo File: +DATA/bjschxsb/onlinelog/redo01b

2、XX2库分析

停止XX2库 Extract进程时正在处理的长事务为

select t.addr,t.XIDUSN,t.XIDSLOT,t.XIDSQN,t.START_DATE from gv$transaction t;

ADDR XIDUSN XIDSLOT XIDSQN START_DAT

---------------- ---------- ---------- ---------- ---------

0700000405B10488 173 30 6643 10-APR-13

截止目前该事务在数据库中仍在进行：

SQL> selectt.SID,t.SERIAL#,t.SCHEMA#,t.SCHEMANAME,t.OSUSER,t.MACHINE,t.PORT,t.TERMINAL,t.PROGRAMfrom gv$session t where taddr='0700000405B10488';

SID SERIAL# SCHEMA# SCHEMANAMEOSUSER MACHINE PORT TERMINAL PROGRAM

---------- -------------------- ---------- ---------- -------------------- ---------------------------------------- ------------------------------

2520 19683 98 SJCK oracle bjschxdbcx03 0 UNKNOWN oracle@bjschxdbcx03(J000)

通过该事务正在进行的 sql以及上一个 sql语句推测，该事务可能由于 Oracle 自动刷新物化视图的内部job发起，不会带来业务数据变化。

SQL> selectt.PREV_SQL_ID,t.SQL_ID from gv$session t where taddr='0700000405B10488';

PREV_SQL_ID SQL_ID

--------------------------

76cckj4yysvua6x5246x8jk7wj

SQL> select sql_textfrom gv$sqltext t where t.SQL_ID = '76cckj4yysvua' order by t.PIECE;

SQL_TEXT

----------------------------------------------------------------

select time_mp, scn,num_mappings, tim_scn_map from smon_scn_tim

e where scn = (select max(scn) from smon_scn_time wherescn

<= :1)

SQL_TEXT

----------------------------------------------------------------

<= :1)

select sql_text fromgv$sqltext t where t.SQL_ID = '6x5246x8jk7wj' order by t.PIECE;

/* MV_REFRESH (MRG) */MERGE INTO "SJCK"."SE_GES_NSDSEWYYS2" "SN

A$" USING ( WITH"TMPDLT$_SE_GES_NSDSEWYYS1" AS ( SELECT /*+ RE

SULT_CACHE(LIFETIME=SESSION)*/ "MAS$"."RID$" "RID$" ,"MAS$"."N

SDEHJ","MAS$"."SDNF", "MAS$"."ZRRDZDAH", DECODE("MAS$".

"OLD_NEW$$",'N', 'I', 'D') "DML$$", "MAS$"."OLD_NEW$$"

"OLD_NEW$$","MAS$"."TIME$$" "TIME$$","MAS$"."DMLTYPE$$" "DMLTY

PE$$" FROM (SELECT "MAS$".*, MIN("MAS$"."SEQ$$") OVER(PARTIT

ION BY"MAS$"."RID$") "MINSEQ$$", MAX("MAS$"."SEQ$$") OVER(PA

RTITION BY"MAS$"."RID$") "MAXSEQ$$" FROM (SELECT CHARTOROWID

("MAS$"."M_ROW$$")RID$ , "MAS$"."NSDEHJ", "MAS$"."SDNF","MAS

$"."ZRRDZDAH" , DECODE("MAS$".OLD_NEW$$, 'N','I', 'D') DML$$,

"MAS$"."DMLTYPE$$""DMLTYPE$$", "MAS$"."SEQUENCE$$" "SEQ$$","MA

S$"."OLD_NEW$$""OLD_NEW$$", "MAS$"."SNAPTIME$$""TIME$$" FROM

"SJCK"."MLOG$_SE_GES_NSDSEWYYS1""MAS$" WHERE"MAS$".SNAPTIME$

恢复该数据库上的 Extract 进程需要用到归档日志 thread 3, seq 5862-6105,从 5862 开始的相当一部分归档日志已被删除，因此会报找不到归档。

Recovery Checkpoint (position of oldest unprocessed transaction in thedata source):

Thread #: 3

Sequence #: 5862

RBA: 18504720

Timestamp: 2013-04-10 01:00:18.000000

SCN: 3098.1717076309 (13307525759317)

Redo File: Not Available

Current Checkpoint (position of last recordread in the data source):

Thread #: 3

Sequence #: 6105

RBA: 39127568

Timestamp: 2013-04-14 11:58:38.000000

SCN: 3099.2202080974 (13312305731278)

Redo File: +DATA/bjschxcx/onlinelog/redo12b

问题原因总结：

目前生产环境所有数据库的 Extract 进程已经按照 Oracle 的建议统一关闭 Bounded Recovery 功能，关闭该功能的后果是，每当 Extract 进程强制停止时，如果进程正在处理既未提交也未回滚的长时间运行事务（无论事务长短），则重启 Extract 进程后，都必须进行 Normal Recovery，必须从这些既未提交也未回滚的事务中最早开始的事务在 Redo 或 Archived log 中的起点位置开始进行 Recovery。

如果未关闭Bounded Recovery，则 Extract 进程会对任何运行时间超过一个 BR 检查点间隔（默认4小时）的事务每隔一个 BR 间隔执行一个检查点，将事务相关的状态和数据写入 BR 检查点文件，这样当 Extract 进程强行终止重启后就会从上一个有效的 BR 检查点或上个 BR 间隔内最早的既未提交也未回滚的事务的起点在日志文件中开始进行 Recovery，通过该功能可以保证 Extract 进程恢复的时间永远不会超过 2 倍的 BR 间隔。

因此，导致本次问题的原因有：

1、GoldenGateExtract 的 Bounded Recovery 功能关闭，该功能官方的 Reference 推荐在未经Oracle Support 推荐情况下，不应对该功能做任何改动。

2、版本升级时在停止 Extract 进程时存在长事务，执行了 forcestop 操作

3、归档日志被删除

4、数据库中存在不正常的长事务

5、数据运维不规范