認識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這張表做實驗。
源端和目標端數據一樣:
在目標端刪除一條數據:
源端和目標端執行info all ,主程序和子程序都是正常的。沒有問題。
下面我們在源端刪除id為2的數據:
此時兩邊再次執行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”,此時應該去查查目標庫中此數據是否被刪除了(我這里當然是刪除了)
我們再往源端添加幾條數據:
不用多說。目標庫中肯定是沒有這些數的,因為已經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,下一條事務。
下面進行看圖講故事環節:
紅色橫線標注的,是此事務進行的操作
黃色橫線標注的,是此事務的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才能進入到目標庫中
可是出乎我意料,我在目標端插入數據:
之后執行:
Alter replicat repfpzx,extrba 1383
目標端並沒有出現我想要的這種情況:
而是依然只有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中一次提交的原因呢?我要是一條一條地提交,不知道是不是會出現我想要的那種結果?
回頭再做實驗吧。