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;
begin :id : sys.dbms_transaction.local_transaction_id; end;
begin :id : sys.dbms_transaction.local_transaction_id; end;
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
select time_mp, scn,num_mappings, tim_scn_map from smon_scn_tim
select time_mp, scn,num_mappings, tim_scn_map from smon_scn_tim
select time_mp, scn,num_mappings, tim_scn_map from smon_scn_tim
e where scn (select max(scn) from smon_scn_time wherescn
e where scn (select max(scn) from smon_scn_time wherescn
e where scn (select max(scn) from smon_scn_time wherescn
e where scn (select max(scn) from smon_scn_time wherescn
:1)
:1)
: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、数据运维不规范
三、解决方案1、重新初始化 能够彻底解决问题 但是存在业务停机时间不可控风险。
2、恢复归档 能够彻底解决问题 存在一定的同步延迟等待。
3、按照抽取时间点跳过该事务 可能存在丢失事务的风险 概率很低但却是存在。
四、处理过程对于XX2库因找不到归档挂起的 Extract 进程 通过恢复归档日志 重启 Extract 进程 等待延迟解决。
对于XX1库因找不到归档挂起的 Extract 进程 经备份厂商核实不存在 Extract 进程执行恢复所需的归档的有效备份 无法恢复归档日志 采取重置Extract 进程按照对 Extract 进程执行 forcestop 操作的时间点重新开始抽取 跳过该长事务。
Forcestop 时间点
2013-04-1411:59:55 INFO OGG-00987 Oracle GoldenGate Command Interpreter for Oracle: GGSCI command (oracle): send ESB_CX7forcestop.
2013-04-1411:59:56 INFO OGG-01021 Oracle GoldenGate Capture for Oracle, esb_cx7.prm: Command received from GGSCI: FORCESTOP.
2013-04-1411:59:30 INFO OGG-00987 Oracle GoldenGate Command Interpreter for Oracle: GGSCI command (oracle): send ESB_ZJ4forcestop.
2013-04-1411:59:30 INFO OGG-01021 Oracle GoldenGate Capture for Oracle, esb_zj4.prm: Command received from GGSCI: FORCESTOP.
重置时间点
alterESB_ZJ4 ,begin 2013-04-14 11:59:30
startESB_ZJ4
alterESB_CX7 ,begin 2013-04-14 11:59:56
startESB_CX7
五、后续建议1、让 Oracle 确认 Bounded Recovery 功能的合理性
2、规范归档日志管理
3、规范数据运维
4、加强数据库长事务监控和优化
5、规范数据库版本升级流程 严格遵循 Oracle 推荐的 OGG 运维规范
本文乃作者原创 转载请注明作者出处及原文链接 否则将追究法律责任
作者 xiangsir
原文链接 http://blog.csdn.net/xiangsir/article/details/8806027
QQ 444367417
MSN xiangsir hotmail.com
![\"\"](\"https://csdnimg.cn/release/blogv2/dist/pc/img/tobarThumbUpactive.png\")
![\"\"](\"https://csdnimg.cn/release/blogv2/dist/pc/img/tobarThumbUp.png\")
点赞 2 ![\"\"](\"https://csdnimg.cn/release/blogv2/dist/pc/img/tobarComment.png\")
![\"\"](\"https://csdnimg.cn/release/blogv2/dist/pc/img/tobarCommentactive.png\")
评论 6本文链接： http://extractgold.immuno-online.com/view-739980.html
