认识logdump分析工具及常用命令:http://book.51cto.com/art/201202/319253.htm

http://www.killdb.com/2012/09/01/goldengate-%E5%AD%A6%E4%B9%A0%E7%B3%BB%E5%88%974-logdump.html

     在OGG中,报ORA-01403: no data found,原因一般就是源端要插入、更新一条数据,目标端已经存在,或者源端要删除一条数据,目标端已经删除了。目标端就会报错,然后挂掉。一般我们处理,就是先确定是那些数据的问题,如果数量少,在目标端删除或者增加这条数据即可,要是设计数量比较多,就跳过这一段的日志应用(比如对一张表进行10条插入或删除)直接进行下一段的应用。如果你无法判断该跳过多少日志,或者嫌麻烦,就直接进行单表的初始化。

下面进行一个简单的跳过日志的实验。

源端配置:

GGSCI (db1) 6> info all

Program Status Group Lag at Chkpt Time Since Chkpt

MANAGER RUNNING

EXTRACT RUNNING EXTFPZX 00:00:00 00:00:03

GGSCI (db1) 7> view params EXTFPZX

extract extfpzx

userid ogg,password ogg

rmthost 192.168.25.101,mgrport 7809

rmttrail /u01/goldengate/dirdat/fp

ddl include mapped objname db_fpzx.*;

table db_fpzx.liuliu;

table db_fpzx.eee;

table db_fpzx.eee1;

GGSCI (db1) 8>

目标端配置:

GGSCI (db2) 4> info all

Program Status Group Lag at Chkpt Time Since Chkpt

MANAGER RUNNING

REPLICAT RUNNING REPFPZX 00:00:00 00:00:00

GGSCI (db2) 5> view params repfpzx

REPLICAT repfpzx

USERID ogg,PASSWORD ogg

discardfile /u01/goldengate/discard/rep2_discard.dsc, append, megabytes 10

DDL INCLUDE MAPPED

DDLERROR DEFAULT IGNORE RETRYOP

ASSUMETARGETDEFS

map db_fpzx.liuliu, target db_fpzx.liuliu;

map db_fpzx.eee, target db_fpzx.eee;

map db_fpzx.eee1, target db_fpzx.eee1;

mapexclude db_fpzx.liu123,TABLEEXCLUDE db_fpzx.liu123;

GGSCI (db2) 6>

(不好意思,做测试的OGG,配置比较简陋,嘿嘿。)

从配置可以看出同步的几张表,我们就用liuliu这张表做实验。

源端和目标端数据一样:

clip_image002

在目标端删除一条数据:

clip_image004

源端和目标端执行info all ,主程序和子程序都是正常的。没有问题。

下面我们在源端删除id为2的数据:

clip_image006

此时两边再次执行info all ,查询状态:

源端是没有问题的,但是目标端变为 ABENDED :

GGSCI (db2) 8> info all

Program Status Group Lag at Chkpt Time Since Chkpt

MANAGER RUNNING

REPLICAT ABENDED REPFPZX 00:00:04 00:00:35

下面是问题分析及处理过程

首先得查询两端的配置(我已经贴出)确定错误日志文件是

/u01/goldengate/discard/rep2_discard.dsc

进入到此目录,查看日志

[oracle@db2 discard]$ pwd

/u01/goldengate/discard

[oracle@db2 discard]$ more rep2_discard.dsc

Oracle GoldenGate Delivery for Oracle process started, group REPFPZX discard file opened: 2016-11-25 15:40:10

Current time: 2016-11-25 15:51:40

Discarded record from action ABEND on error 1403

OCI Error ORA-01403: no data found, SQL <DELETE FROM "DB_FPZX"."LIULIU" WHERE "ID" = :b0>

Aborting transaction on /u01/goldengate/dirdat/fp beginning at seqno 6 rba 1259

error at seqno 6 rba 1259

Problem replicating DB_FPZX.LIULIU to DB_FPZX.LIULIU

Record not found

Mapping problem with delete record (target format)...

*

ID = 2

*

Process Abending : 2016-11-25 15:51:40

日志很清楚地指出了在删除DB_FPZX.LIULIU表中ID为2的数据的时候,出了错“ORA-01403: no data found”,此时应该去查查目标库中此数据是否被删除了(我这里当然是删除了)

我们再往源端添加几条数据:

clip_image008

不用多说。目标库中肯定是没有这些数的,因为已经ABENDED了。

下面分析dump文件:

目标端

GGSCI (db2) 10> info repfpzx

REPLICAT REPFPZX Last Started 2016-11-25 15:40 Status ABENDED

Checkpoint Lag 00:00:04 (updated 00:17:23 ago)

Log Read Checkpoint File /u01/goldengate/dirdat/fp000006

2016-11-25 15:51:36.385195 RBA 1259

查询显示repfpzx此时用的文件是/dirdat/fp000006,咱们就用logdump工具打开这个文件看看

[oracle@db2 goldengate]$ ./logdump

Oracle GoldenGate Log File Dump Utility for Oracle

Version 11.2.1.0.1 OGGCORE_11.2.1.0.1_PLATFORMS_120423.0230

Copyright (C) 1995, 2012, Oracle and/or its affiliates. All rights reserved.

Logdump 36 >open ./dirdat/fp000006

Current LogTrail is /u01/goldengate/dirdat/fp000006

Logdump 37 >count

LogTrail /u01/goldengate/dirdat/fp000006 has 9 records

Total Data Bytes 1347

Avg Bytes/Record 149

Delete 1

Insert 6

RestartOK 1

Others 1

Before Images 1

After Images 7

Average of 5 Transactions

Bytes/Trans ..... 355

Records/Trans ... 1

Files/Trans ..... 1

Count命令显示信息。由于这个文件操作比较少,可以看见里面的记录包括一次删除,6次插入。一次删除就是删除id为2的记录。6次插入就是我除了插入2,3,4,5,6以外还有一次插入(我之前插入id为2的记录)。当然了,这些数据没啥用,时间久了这里面的delete和insert计数太多了,根本不可能也没必要去搞清楚都是谁。

下面咱们看细节:

Logdump 38 >pos 1259 ----pos + RBA号,直接跳到这个记录上,这里为什么跳到1259呢?因为info repfpzx 命令查询出来的结果告诉我们,1259是他当前正在处理的事务。

Reading forward from RBA 1259

Logdump 39 >sfh ----寻找此号码之后,最近的一个有效记录。N表示next,下一条事务。

clip_image010

下面进行看图讲故事环节:

红色横线标注的,是此事务进行的操作

黄色横线标注的,是此事务的BRA,由此可见,BRA并不是每个都+1的,而是跳着的!

红色箭头标注的,还用我说吗?就是关键数据啊2,3,4,不都是ID嘛!

由此可见,RBA为1259的事务是个删除操作,它涉及到的是db_fpzx.liuliu表中id为2的数据。和我们看dsc文件是一样的结果。(废话~~~)

注:关于logdump工具的一些关键命令:

Pos 跳到某一个RBA,这个RBA不需要一定存在,需要配合sfh使用

Sfh 跳到当前RBA的下一个有效RBA

pos eof 跳到文件末尾

Pos reverse 反向读取

我们目标端数据既然已经删除此数据了,我们就需要跳过1259,直接从1383开始恢复就可以了。

(另一种就是手工添加这条数据,启动进程,日志自然会删除它,然后就进行到下一步了)

命令是:

Alter replicat repfpzx(进程名),extrba 1383

执行完之后,进程会变为STOPPED状态,start它就行了。

PS:我本来以为在执行以上命令之前,先往目标库中插入ID为4的数据,OGG会把我在源库中插入的

insert into liuliu (id,name,www) values (2,'liu','liuliu222');

insert into liuliu (id,name,www) values (3,'liu','liuliu333');

先“复原”到目标库,然后在

insert into liuliu (id,name,www) values (4,'liu','liuliu444');

这一句上再次ABENDED,然后此时目标库中的数据应该是有1、2、3、4,没有5、6。

我再执行Alter replicat repfpzx(进程名),extrba (ID为5的RBA号),重启进程,5、6才能进入到目标库中

可是出乎我意料,我在目标端插入数据:

clip_image012

之后执行:

Alter replicat repfpzx,extrba 1383

目标端并没有出现我想要的这种情况:

clip_image014

而是依然只有1和4 两条数据,而且进程没有起来。

查看dsc文件显示:

……省略……

Current time: 2016-11-25 16:44:17

Discarded record from action ABEND on error 1

OCI Error ORA-00001: unique constraint (DB_FPZX.SYS_C0010982) violated (status = 1). INSERT INTO "DB_FPZX"."LIULIU" ("ID","AGE","NAME","EEE","WWW") V

ALUES (:a0,:a1,:a2,:a3,:a4)

Aborting transaction on /u01/goldengate/dirdat/fp beginning at seqno 6 rba 1383

error at seqno 6 rba 1697

Problem replicating DB_FPZX.LIULIU to DB_FPZX.LIULIU

Mapping problem with insert record (target format)...

*

ID = 4

AGE = NULL

NAME = liu

EEE = NULL

WWW = liuliu444

*

Continuing to discard records up to the last discarded record from action ABEND

Operation discarded from seqno 6 rba 1383

Aborted insert from DB_FPZX.LIULIU to DB_FPZX.LIULIU (target format)...

*

ID = 2

AGE = NULL

NAME = liu

EEE = NULL

WWW = liuliu222

*

Operation discarded from seqno 6 rba 1551

Aborted insert from DB_FPZX.LIULIU to DB_FPZX.LIULIU (target format)...

*

ID = 3

AGE = NULL

NAME = liu

EEE = NULL

WWW = liuliu333

*

Process Abending : 2016-11-25 16:44:17

Oracle GoldenGate Delivery for Oracle process started, group REPFPZX discard file opened: 2016-11-25 16:52:14

感觉OGG将这些插入语句

insert into liuliu (id,name,www) values (2,'liu','liuliu222');

insert into liuliu (id,name,www) values (3,'liu','liuliu333');

insert into liuliu (id,name,www) values (4,'liu','liuliu444');

insert into liuliu (id,name,www) values (5,'liu','liuliu555');

insert into liuliu (id,name,www) values (6,'liu','liuliu666');

当成一个整体执行了,只要有一条没过去,其他的也就够不去。

是不是因为我是同一个session中一次提交的原因呢?我要是一条一条地提交,不知道是不是会出现我想要的那种结果?

回头再做实验吧。