最近在測試goldengate 從ORACLE 同步到MYSQL，總是出現某一張表的程式同步會出現異常終止，在開啟實時同步之前，已透過ogg初始化將資料遷移到mysql，後開啟實時同步，在抽取複製了部分資料後就突然終止，

2018-10-27 17:28:15 ERROR OGG-00768 DYNSQL: Preparing SQL statement (ID = 0) failed. SQL error (1064). You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '%T SET %S WHERE %W' at line 1.

***********************************************************************

* ** Run Time Statistics ** *

***********************************************************************

Reading /data/ogg/dirdat/b1000000177, current RBA 126808413, 6 records, m_file_seqno = 177, m_file_rba = 126808413

Report at 2018-10-27 17:28:15 (activity since 2018-10-27 17:28:14)

No records were replicated.

Last log location read:

FILE: /data/ogg/dirdat/b1000000177

SEQNO: 177

RBA: 126808413

TIMESTAMP: 2018-10-27 17:25:31.998288

EOF: NO

READERR: 0

2018-10-27 17:28:15 ERROR OGG-01668 PROCESS ABENDING.

關於這個錯誤：

check the manual that corresponds to your MySQL server version for the right syntax to use near '%T SET %S WHERE %W' at line 1.

該錯誤看起來，是ogg 複製程式在向mysql執行sql時出現了語法錯誤。

最開始的分析思路是這樣的：

為什麼會出現語法錯誤？

2.並不是所有事務所有語句會同步錯誤

3.那是在哪一條語句出現了錯誤。

關於為什麼會出現語法錯誤？

首先是懷疑是觸發了mysql 保留字導致，但如果是這樣是否每個事務語句的執行都應該是有問題。

mos上說是bug,但最終報錯的位置是不同的。

MySql Replicat Abend With SQL Error 1064 (文件 ID 1500680.1)

On : 11.2.1.0.1 version, REPLICAT executable

When attempting to start the replicat the following error occurs
the following error occurs.

ERROR
-----------------------
"DYNSQL: Preparing SQL statement (ID = 0) failed. SQL error (1064). You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'key,value,`created_at`,`updated_at`) VALUES (?,?,?,?,?"

於是，開始想辦法最終是在什麼語句執行會出現錯誤。從以上報錯的資訊，使用 logdump 檢視相應位置 rba 126808413 資料資訊。

./logdump

Oracle GoldenGate Log File Dump Utility for MySQL

Version 12.3.0.1.5 OGGCORE_12.3.0.1.0_PLATFORMS_180501.2124

Logdump 213 >open /data/ogg/dirdat/b1000000177

Current LogTrail is /data/ogg/dirdat/b1000000177

Logdump 214 >pos 126808413

Reading forward from RBA 126808413

Logdump 215 >n

2018/10/27 17:25:31.998.288 GGSUnifiedUpdate Len 36 RBA 126808413

Name: xxxxxxx (TDR Index: 11)

After Image: Partition 12 G s

1000 0000 0000 0c00 0000 0800 3237 3432 3337 3331 | ............27423731 <<<<<<<報錯資料的主鍵

0000 0c00 0000 0800 3237 3432 3337 3331 | ........27423731

Logdump 216 >

該條SQL操作的資料是27423731 主鍵的這行資料，且這是條UPDATE語句。

在複製程式端解析trail 檔案中的sql。

edit params xxx

加入以下引數

showsyntax

nodynsql

nobinarychars

執行：

./replicat paramfile /data/ogg/dirprm/rebpmc3.prm

之後一直回車直到報錯。最後執行的SQL如下：

INSERT INTO `xxx`.xxxMATERIAL` (` Materialid `,`Materialname`,`Productid`,`Picsize`,`Piclength_Bak`,`Picwidth_Bak`,`Picheight_Bak`,`M........atus`) VALUES (' 27429245 ','辦xxx',NULL,NULL,NULL,NULL,NULL,0,0,'C00000000','00435320','1000353061','2018-10-27 17:25:24.000000',0,NULL,NULL,0,0,21,0,0,0,0,NULL,'cabinet_floor',0,0,'12005458,00658412,08989038,00193428,00658388,02933575,14414950,00294959,00284882,00190795,0012........

(S)top display, (K)eep displaying (default):

2018-10-27 17:28:15 WARNING OGG-00869 SQLFormatter::ToSQLUpdate invalid statement object, no SETParams.

Source Context :

最後執行的的SQL實際是最後一次正常執行的語句，這是insert語句，在執行完該insert 語句之後，執行下一條語句便報錯了。並且結合以上，該報錯sql連語法檢測都不透過。

在MYSQL端，我想到的是開啟通用日誌，發現MYSQL 仍然只能看到上一條

mysql> set global general_log=ON

-> ;

Query OK, 0 rows affected (0.00 sec)

SQL error (1064). You have an error in your SQL syntax;

這個錯誤，當我們的sql邏輯出現異常時，即mysql檢測失敗，此時根本不會在資料庫中執行，這也是為什麼以上無法捕捉報錯sql的原因了。

那麼，此時就得想辦法從源端查詢了。

在源端抽取程式配置 formatsql 引數，將抽取資料的SQL列印出來。

GGSCI (mha-datacenter02 as ggs@gjlvdb) 150> edit params exttest

extract exttest

。。。

FORMATSQL ORACLE, NONAMES <<<<加入這一行

ExtTrail ./dirdat/t1

檢視相應語句：

~ less t1000000001

INSERT INTO xxxx VALUES (' 27429245 ','辦公',NULL,NULL,NULL,NULL,NULL,0,'0','C00000000','00435320','1000353061',TO_DATE('2018-10-27:17:25:24','YYYY-MM-DD:HH24:MI:SS'),0,NULL,NULL,0,0,21,0.00,0.00,0.00,0,NULL,'cabinet_floor',0,0,'12005458,00658412,08989038,00193428,00658388,02933575,144149.....L);

COMMIT WORK;

--B,2018-10-27:17:25:32.000000,1540632332,1853

UPDATE xxxx SET MATERIALID='27423731' WHERE MATERIALID='27423731';<<<<<<<

COMMIT WORK;

由此在源端找到了該報錯的SQL,發現這是一條更新主鍵的SQL.在實際應用中產生這樣的SQL真的很不應該。

其實，這條sql在執行上也並沒有毛病，且不應該會引起語法錯誤啊。

mysql> UPDATE xxx SET MATERIALID='27423731' WHERE MATERIALID='27423731';

Query OK, 0 rows affected (0.00 sec)

Rows matched: 0 Changed: 0 Warnings: 0

我直接在MYSQL資料庫中執行是正常的。

而在OGG 中對主鍵的更新是否會存在影響。由於是在初始化階段，我看到我的配置裡新增了 HANDLECOLLISIONS 的引數， HANDLECOLLISIONS 的引數本意是在初始化階段解決一些目標端找不到資料的情況。

Missing updates are ignored.
Missing deletes are ignored.
Duplicate inserts are turned into updates.

很明顯和我這種情況不符，但在mos的一篇文章看到這樣一句話，讓我感覺會有影響。

the PK is not available at target side, then this error is expected, because HANDLECOLLISIONS turns the PK update into an insert as result of no target record to update.

於是將 HANDLECOLLISIONS 引數去除，發現同步正常了。

在未新增 HANDLECOLLISIONS 的情況下，在源端執行UPDATE xxx SET MATERIALID='27423731' WHERE MATERIALID='27423731';發現複製進行其實可以讀到。

Replicating from PMC.CWDTEST11 to pmc.cwdtest11:

*** Total statistics since 2018-10-27 22:18:47 ***

Total inserts 0.00

Total updates 7.00

Total deletes 0.00

Total discards 0.00

Total operations 7.00

但是，在MYSQL的通用日誌並沒有記錄相應的sql,很明顯ogg並沒有將該sql 拿到mysql中執行提交，也對，這本身就是毫無意義的sql，傻子才寫出這樣的sql邏輯。

2018-10-27T15:19:41.702275Z 4652 Query commit

2018-10-27T15:19:51.705939Z 4652 Query begin

2018-10-27T15:19:51.706025Z 4652 Query commit

2018-10-27T15:19:53.706920Z 4652 Query begin

2018-10-27T15:19:53.707090Z 4652 Query UPDATE `pmc`.`checkpoint` SET last_update_ts = current_timestamp, rba = 414723, version=1, seqno = 0, audit_ts = '2018-10-27 23:19:47.986899', log_bsn = NULL, log_csn = '25475087', log_xid = NULL, log_cmplt_csn = '25475087', log_cmplt_xids = '0.9.3.21639' WHERE group_name = 'REPTEST' AND group_key = '3895688168'

2018-10-27T15:19:53.707402Z 4652 Query commit

2018-10-27T15:20:03.712012Z 4652 Query begin

2018-10-27T15:20:03.712207Z 4652 Query UPDATE `pmc`.`checkpoint` SET last_update_ts = current_timestamp, rba = 418129, version=1, seqno = 0, audit_ts = '2018-10-27 23:19:57.986800', log_bsn = NULL, log_csn = '25475087', log_xid = NULL, log_cmplt_csn = '25475087', log_cmplt_xids = '0.9.3.21639' WHERE group_name = 'REPTEST' AND group_key = '3895688168'

2018-10-27T15:20:03.712522Z 4652 Query commit

2018-10-27T15:20:13.716284Z 4652 Query begin

ogg oracle 同步mysql的一個莫名其妙的語法錯誤排查GG-00768 SQL error (1064)

相關文章