Oracle OGG 到 Kafka OGG-01431 OGG-01003 OGG-01151 OGG-01296 OGG-01668

问题描述： 监控告警OGG 应用延迟，应用进程异常，登录OGG 检查发现源端进程正常，对端异常报错如下： OGG-01431 OGG-01003 OGG-01151  OGG-01296 OGG-01668 Oracle ：SQL*Plus: Release 11.2.0.4.0 Production OGG ：Version 12.3.0.1.191015 OGGCORE_12.3.0.1.0 OGGBP_PLATFORMS_190920.1011_FBO 报错信息： 2021-04-07T10:53:47.979+0800  WARNING OGG-01431  Oracle GoldenGate Delivery, kafka.prm:  Aborted grouped transaction on RP.OM_BUSI_RECORD_202101, Mapping error. 2021-04-07T10:53:47.979+0800  WARNING OGG-01003  Oracle GoldenGate Delivery, kafka.prm:  Repositioning to rba 3195750 in seqno 1632. 2021-04-07T10:53:48.124+0800  WARNING OGG-01151  Oracle GoldenGate Delivery, kafka.prm:  Error mapping from REPORT.XT_ORDER_FORWORD_202101 to REPORT.XT_ORDER_FORWORD_202101. 2021-04-07T10:53:48.133+0800  ERROR   OGG-01296  Oracle GoldenGate Delivery, kafka.prm:  Error mapping from REPORT.XT_ORDER_FORWORD_202101 to REPORT.XT_ORDER_FORWORD_202101. 2021-04-07T10:53:48.142+0800  ERROR   OGG-01668  Oracle GoldenGate Delivery, kafka.prm:  PROCESS ABENDING. 通过report 查看信息如下： 省略...... Database Language and Character Set: *********************************************************************** **                     Run Time Messages                             ** *********************************************************************** 2021-04-07 13:10:28  INFO    OGG-02243  Opened trail file /ogg/ogg_home1/dirdat/k1000002167 at 2021-04-07 13:10:28.713439. 2021-04-07 13:10:28  INFO    OGG-03506  The source database character set, as determined from the trail file, is zhs16gbk. 2021-04-07 13:10:28  INFO    OGG-06506  Wildcard MAP resolved (entry *.*): Map REPORT.XT_ORDER_FORWORD_202101, Target REPORT.XT_ORDER_FORWORD_202101. 2021-04-07 13:10:28  INFO    OGG-02756  The definition for table REPORT.XT_ORDER_FORWORD_202101 is obtained from the trail file. 2021-04-07 13:10:28  INFO    OGG-06511  Using following columns in default map by name: 主键，列2，列3，列4，列5，列6...... _ORG_ID, DONE_DATE, OP_ID, ORG_ID, MGMT_DISTRICT, MGMT_COUNTY, REGION_ID. 2021-04-07 13:10:28  INFO    OGG-06510  Using the following key columns for target table REPORT.XT_ORDER_FORWORD_202101: 主键. 2021-04-07 13:10:28  INFO    OGG-03010  Performing implicit conversion of column data from character set zhs16gbk to UTF-8. 2021-04-07 13:10:28  WARNING OGG-01431  Aborted grouped transaction on REPORT.XT_ORDER_FORWORD_202101, Mapping error. 2021-04-07 13:10:28  WARNING OGG-01003  Repositioning to rba 13712 in seqno 2167. 2021-04-07 13:10:28  WARNING OGG-01151  Error mapping from REPORT.XT_ORDER_FORWORD_202101 to REPORT.XT_ORDER_FORWORD_202101. Source Context :   SourceModule            : [er.replicat.errors]   SourceID                : [/scratch/aime/adestore/views/aime_adc4150533/oggcore/OpenSys/src/app/er/replicat/reperrors.cpp]   SourceMethod            : [repError]   SourceLine              : [1673]   ThreadBacktrace         : [15] elements                           : [/ogg/ogg_home1/libgglog.so(CMessageContext::AddThreadContext()+0x1e) [0x7fe9f60b50ae]]                           : [/ogg/ogg_home1/libgglog.so(CMessageFactory::CreateMessage(CSourceContext*, unsigned int, ...)+0x6ac) [0x7fe9f60a59bc]]                           : [/ogg/ogg_home1/libgglog.so(_MSG_QualTableName_QualTableName(CSourceContext*, int, ggs::gglib::ggapp::CQualDBObjName<(DBO bjType)1> const&, ggs::gglib::ggapp::CQualDBObjName<(DBObjType)1> const&, CMessageFactory::MessageDisposition)+0x74) [0x7fe9f609ce84]]                           : [/ogg/ogg_home1/replicat(ggs::er::ReplicatContext::repError(short, int, char const*, extr_ptr_def*, ggs::gglib::gglcr::Co mmonLCR const*, std_rec_hdr_def*, char*, ObjectMetadata*, bool)+0x2821) [0x63a4c1]]                           : [/ogg/ogg_home1/replicat(ggs::er::ReplicatContext::replicate_io(ggs::gglib::gglcr::CommonLCR const*, ggs::gglib::gglcr::C ommonLCR*, extr_ptr_def*, bool, int&, RepCsn&, bool*)+0x29b9) [0x6eb9a9]]                           : [/ogg/ogg_home1/replicat(ggs::er::ReplicatContext::processRecord(ggs::gglib::gglcr::CommonLCR const*, ggs::gglib::gglcr:: CommonLCR*, extr_ptr_def*&, extr_ptr_def*&, bool&, int&, bool, RepCsn&)+0x318) [0x6f9958]]                           : [/ogg/ogg_home1/replicat(ggs::er::ReplicatContext::processReplicatLoop()+0x4614) [0x6314f4]]                           : [/ogg/ogg_home1/replicat(ggs::er::ReplicatContext::run()+0x45) [0x610585]]                           : [/ogg/ogg_home1/replicat() [0x6e50ef]]                           : [/ogg/ogg_home1/replicat(ggs::gglib::MultiThreading::MainThread::ExecMain()+0x5e) [0x7e2cde]]                           : [/ogg/ogg_home1/replicat(ggs::gglib::MultiThreading::Thread::RunThread(ggs::gglib::MultiThreading::Thread::ThreadArgs*)+0 x173) [0x7e70a3]]                           : [/ogg/ogg_home1/replicat(ggs::gglib::MultiThreading::MainThread::Run(int, char**)+0x140) [0x7e7910]]                           : [/ogg/ogg_home1/replicat(main+0x3b) [0x6e7e8b]]                           : [/lib64/libc.so.6(__libc_start_main+0xf5) [0x7fe9ee747b35]]                           : [/ogg/ogg_home1/replicat() [0x550851]] 2021-04-07 13:10:28  ERROR   OGG-01296  Error mapping from REPORT.XT_ORDER_FORWORD_202101 to REPORT.XT_ORDER_FORWORD_202101. *********************************************************************** *                   ** Run Time Statistics **                         * *********************************************************************** Last record for the last committed transaction is the following: ___________________________________________________________________ Trail name :  /ogg/ogg_home1/dirdat/k1000002167 Hdr-Ind    :     E  (x45)     Partition  :     .  (x0c) UndoFlag   :     .  (x00)     BeforeAfter:     A  (x41) RecLength  :   345 (x0159)    IO Time    : 2021-04-07 10:50:16.010538 IOType     :     5  (x05)     OrigNode   :   255  (xff) TransInd   :     .  (x03)     FormatType :     R  (x52) SyskeyLen  :     0  (x00)     Incomplete :     .  (x00) AuditRBA   :      55981       AuditPos   : 696473840 Continued  :     N  (x00)     RecCount   :     1  (x01) 2021-04-07 10:50:16.010538 Insert             Len   345 RBA 13712 TDR Index: 3 ___________________________________________________________________ Reading /ogg/ogg_home1/dirdat/k1000002167, current RBA 14182, 1 records, m_file_seqno = 2167, m_file_rba = 14182 Report at 2021-04-07 13:10:28 (activity since 2021-04-07 13:10:28) From Table REPORT.XT_ORDER_FORWORD_202101 to REPORT.XT_ORDER_FORWORD_202101:        #                   inserts:         1        #                   updates:         0        #                   deletes:         0        #                  discards:         1 2021-04-07 13:10:28  INFO    OGG-06510  Using the following key columns for target table REPORT.XT_ORDER_FORWORD_202101: 主键. 通过报错信息判断是数据插入异常，我们初步怀疑是表结构发生变化，通过检查表结构和索引都没有发生变化，唯一的变化就是表变成了2021年的年月表了，而且看到同步信息数该表只有主键一列进行映射同步，此时想到可能是表的附件日志问题， 登录OGG 核实如下： GGSCI (reportdb2 as ogg@reportdb2) 3> info trandata REPORT.XT_ORDER_FORWORD_202101 Logging of supplemental redo log data is disabled for table REPORT.XT_ORDER_FORWORD_202101. 而以前表的属性是： GGSCI (reportdb2as ogg@reportdb2) 8> info trandata REPORT.XT_ORDER_FORWORD_202011 Logging of supplemental redo log data is enabled for table REPORT.XT_ORDER_FORWORD_202011. All columns supplementally logged for table REPORT.XT_ORDER_FORWORD_202011. 至此问题找到了，是由于2021年同步的新表没有开启最小附加日志 GGSCI (reportdb) 2> dblogin  USERID 配置的OGG用户,PASSWORD 密码 Successfully logged into database. GGSCI (reportdb as ogg@reportdb) 5> add trandata REPORT.XT_ORDER_FORWORD_2021?? 省略..... ?GGSCI (reportdb as ogg@reportdb) 5> info trandata REPORT.XT_ORDER_FORWORD_2021?? 省略..... 由于业务反应中间数据量已经不需要要，数据量太大，且由于我们本身传输的数据不满足无法应用，所以我们跳过直接使用新生成的文件 GGSCI (kafkaserver1) 6> alter REPLICAT  KAFKA, extseqno 000002167 extrba 0 2021-04-07 12:11:54  INFO    OGG-06594  Replicat R_KAFKA1 has been altered. Even the start up position might be updated, duplicate suppression remains active in next startup. To override duplicate suppression, start R_KAFKA1 with NOFILTERDUPTRANSACTIONS option. REPLICAT altered. GGSCI (kafkaserver1) 7> start REPLICAT  KAFKA GGSCI (kafkaserver1) 17> info all Program     Status      Group       Lag at Chkpt  Time Since Chkpt MANAGER     RUNNING                                            REPLICAT       RUNNING     KAFKA    00:00:00      00:00:02    GGSCI (kafkaserver1) 18>