联系:手机/微信(+86 17813235971) QQ(107644445)
作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]
一、错误检查
[oracle@srtcreen ~]$ ggsci Oracle GoldenGate Command Interpreter for Oracle Version 11.1.1.1.1 OGGCORE_11.1.1.1.1_PLATFORMS_110729.1700 Linux, x64, 64bit (optimized), Oracle 10g on Jul 29 2011 19:43:29 Copyright (C) 1995, 2011, Oracle and/or its affiliates. All rights reserved. GGSCI (srtcreen) 1> info all Program Status Group Lag Time Since Chkpt MANAGER RUNNING REPLICAT RUNNING R_1 00:00:00 00:00:07 REPLICAT RUNNING R_2 00:00:00 00:00:05 REPLICAT ABENDED R_3 19:19:34 00:17:33 REPLICAT STOPPED R_4 00:00:00 19:44:24 REPLICAT STOPPED R_5 00:00:00 19:44:13 GGSCI (srtcreen) 2> view report r_3 *********************************************************************** Oracle GoldenGate Delivery for Oracle Version 11.1.1.1.1 OGGCORE_11.1.1.1.1_PLATFORMS_110729.1700 Linux, x64, 64bit (optimized), Oracle 10g on Sep 13 2011 21:33:03 Copyright (C) 1995, 2011, Oracle and/or its affiliates. All rights reserved. Starting at 2011-12-02 16:36:58 *********************************************************************** Operating System Version: Linux Version #1 SMP Fri Apr 2 14:58:14 EDT 2010, Release 2.6.18-194.el5 Node: srtcreen Machine: x86_64 soft limit hard limit Address Space Size : unlimited unlimited Heap Size : unlimited unlimited File Size : unlimited unlimited CPU Time : unlimited unlimited Process id: 13398 Description: *********************************************************************** ** Running with the following parameters ** *********************************************************************** replicat r_3 ASSUMETARGETDEFS HANDLECOLLISIONS SETENV (NLS_LANG =AMERICAN_AMERICA.ZHS16GBK) Set environment variable (NLS_LANG=AMERICAN_AMERICA.ZHS16GBK) userid it1ogg, password ******** --file for dicarded transaction -- discardfile /opt/OGG/discard/R_3.txt, append, megabytes 100 DDL MAP CSCNEW.TAB_CS_CALL_PICKUP, TARGET SRT_CREEN.TAB_CS_CALL_PICKUP, KEYCOLS (CALL_ID); CACHEMGR virtual memory values (may have been adjusted) CACHEBUFFERSIZE: 64K CACHESIZE: 512M CACHEBUFFERSIZE (soft max): 4M CACHEPAGEOUTSIZE (normal): 4M PROCESS VM AVAIL FROM OS (min): 1G CACHESIZEMAX (strict force to disk): 881M Database Version: Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bi PL/SQL Release 10.2.0.4.0 - Production CORE 10.2.0.4.0 Production TNS for Linux: Version 10.2.0.4.0 - Production NLSRTL Version 10.2.0.4.0 - Production Database Language and Character Set: NLS_LANG = "AMERICAN_AMERICA.ZHS16GBK" NLS_LANGUAGE = "AMERICAN" NLS_TERRITORY = "AMERICA" NLS_CHARACTERSET = "ZHS16GBK" For further information on character set settings, please refer to user manual. *********************************************************************** ** Run Time Messages ** *********************************************************************** Opened trail file /opt/OGG/dirdat/U3000000 at 2011-12-02 16:36:58 MAP resolved (entry CSCNEW.TAB_CS_CALL_PICKUP): MAP CSCNEW.TAB_CS_CALL_PICKUP, TARGET SRT_CREEN.TAB_CS_CALL_PICKUP, KEYCOLS (CALL_ID); Using following columns in default map by name: PICKUP_ID, CALL_ID, CALL_SERIAL, USER_ID, PICKUP_TIME, CALL_RESULT, FAIL_REASON, CALL_TIME, CALL_DURA, END_TIME Using the following key columns for target table SRT_CREEN.TAB_CS_CALL_PICKUP: CALL_ID. 2011-12-02 16:36:58 WARNING OGG-00869 OCI Error ORA-01407: cannot update ("SRT_CREEN"."TAB_CS_CALL_PICKUP"."PICKUP_ID") to NULL (status = 1407), SQL <UPDAT E "SRT_CREEN"."TAB_CS_CALL_PICKUP" SET "PICKUP_ID" = :a0,"CALL_SERIAL" = :a2,"USER_ID" = :a3,"PICKUP_TIME" = :a4,"CALL_RESULT" = :a5,"FAIL_REASON" = :a6,"CAL L_TIME" = :a7,"CALL_DURA" = :a8,"END_T>. 2011-12-02 16:36:58 WARNING OGG-01004 Aborted grouped transaction on 'SRT_CREEN.TAB_CS_CALL_PICKUP', Database error 1407 (OCI Error ORA-01407: cannot updat e ("SRT_CREEN"."TAB_CS_CALL_PICKUP"."PICKUP_ID") to NULL (status = 1407), SQL <UPDATE "SRT_CREEN"."TAB_CS_CALL_PICKUP" SET "PICKUP_ID" = :a0,"CALL_SERIAL" = :a2,"USER_ID" = :a3,"PICKUP_TIME" = :a4,"CALL_RESULT" = :a5,"FAIL_REASON" = :a6,"CALL_TIME" = :a7,"CALL_DURA" = :a8,"END_T>). 2011-12-02 16:36:58 WARNING OGG-01003 Repositioning to rba 924 in seqno 0. 2011-12-02 16:36:59 WARNING OGG-01154 SQL error 1407 mapping CSCNEW.TAB_CS_CALL_PICKUP to SRT_CREEN.TAB_CS_CALL_PICKUP OCI Error ORA-01407: cannot update ( "SRT_CREEN"."TAB_CS_CALL_PICKUP"."PICKUP_ID") to NULL (status = 1407), SQL <UPDATE "SRT_CREEN"."TAB_CS_CALL_PICKUP" SET "PICKUP_ID" = :a0,"CALL_SERIAL" = :a2 ,"USER_ID" = :a3,"PICKUP_TIME" = :a4,"CALL_RESULT" = :a5,"FAIL_REASON" = :a6,"CALL_TIME" = :a7,"CALL_DURA" = :a8,"END_T>. 2011-12-02 16:36:59 WARNING OGG-01003 Repositioning to rba 924 in seqno 0. *********************************************************************** * ** Run Time Statistics ** * *********************************************************************** Last record for the last committed transaction is the following: ___________________________________________________________________ Trail name : /opt/OGG/dirdat/U3000000 Hdr-Ind : E (x45) Partition : . (x04) UndoFlag : . (x00) BeforeAfter: A (x41) RecLength : 157 (x009d) IO Time : 2011-12-01 21:17:24.084108 IOType : 15 (x0f) OrigNode : 255 (xff) TransInd : . (x03) FormatType : R (x52) SyskeyLen : 0 (x00) Incomplete : . (x00) AuditRBA : 3225 AuditPos : 42227728 Continued : N (x00) RecCount : 1 (x01) 2011-12-01 21:17:24.084108 FieldComp Len 157 RBA 924 Name: CSCNEW.TAB_CS_CALL_PICKUP ___________________________________________________________________ Reading /opt/OGG/dirdat/U3000000, current RBA 924, 0 records Report at 2011-12-02 16:36:59 (activity since 2011-12-02 16:36:58) From Table CSCNEW.TAB_CS_CALL_PICKUP to SRT_CREEN.TAB_CS_CALL_PICKUP: # inserts: 0 # updates: 0 # deletes: 0 # discards: 1 DDL replication statistics: Operations: 0 Mapped operations: 0 Unmapped operations: 0 Other operations: 0 Excluded operations: 0 Errors: 0 Retried errors: 0 Discarded errors: 0 Ignored errors: 0 Last log location read: FILE: /opt/OGG/dirdat/U3000000 SEQNO: 0 RBA: 924 TIMESTAMP: 2011-12-01 21:17:24.084108 EOF: NO READERR: 0 2011-12-02 16:36:59 ERROR OGG-01668 PROCESS ABENDING. --发现奇怪现象,我2011-12-02早上过来检查这个,发现时间竟然显示2011-12-02 16:36:59,第一反应系统时间错误,继续检查 GGSCI (srtcreen) 2> info r_2 REPLICAT R_2 Last Started 2011-12-01 21:09 Status RUNNING Checkpoint Lag 00:00:00 (updated 00:00:05 ago) Log Read Checkpoint File /opt/OGG/dirdat/U2000000 2011-12-02 17:01:29.927591 RBA 6234 GGSCI (srtcreen) 3> exit [oracle@srtcreen OGG]$ cd dirdat [oracle@srtcreen dirdat]$ ll total 396 -rw-rw-rw- 1 oracle oinstall 0 Dec 1 21:10 U1000000 -rw-rw-rw- 1 oracle oinstall 5984 Dec 2 05:36 U2000000 -rw-rw-rw- 1 oracle oinstall 392258 Dec 2 16:52 U3000000 [oracle@srtcreen dirdat]$ stat U3000000 File: `U3000000' Size: 392258 Blocks: 776 IO Block: 4096 regular file Device: fd00h/64768d Inode: 213844220 Links: 1 Access: (0666/-rw-rw-rw-) Uid: ( 501/ oracle) Gid: ( 501/oinstall) Access: 2011-12-02 16:36:59.000000000 +0800 Modify: 2011-12-02 16:52:55.000000000 +0800 Change: 2011-12-02 16:52:55.000000000 +0800 ###############查看源端数据库服务器时间##################### [oracle@tykf ~]$ date Fri Dec 2 08:50:10 CST 2011 [oracle@tykf ~]$ ggsci Oracle GoldenGate Command Interpreter for Oracle Version 11.1.1.0.0 Build 078 Linux, x64, 64bit (optimized), Oracle 10 on Jul 28 2010 13:21:11 Copyright (C) 1995, 2010, Oracle and/or its affiliates. All rights reserved. GGSCI (tykf) 1> info all Program Status Group Lag Time Since Chkpt MANAGER RUNNING EXTRACT RUNNING EXT_1 00:00:00 00:00:05 EXTRACT RUNNING EXT_2 00:00:00 00:00:01 EXTRACT RUNNING EXT_3 00:00:00 00:00:05 EXTRACT STOPPED EXT_4 00:00:00 21:59:56 EXTRACT STOPPED EXT_5 00:00:00 21:59:28 EXTRACT RUNNING P_1 00:00:00 00:00:04 EXTRACT RUNNING P_2 00:00:00 00:00:04 EXTRACT RUNNING P_3 00:00:00 00:00:05 EXTRACT STOPPED P_4 00:00:00 21:56:42 EXTRACT STOPPED P_5 00:00:00 21:56:11 GGSCI (tykf) 2> info ext_3 EXTRACT EXT_3 Last Started 2011-12-01 13:11 Status RUNNING Checkpoint Lag 00:00:00 (updated 00:00:03 ago) Log Read Checkpoint Oracle Redo Logs 2011-12-02 08:50:06 Seqno 3233, RBA 32267264 GGSCI (tykf) 3> info p_3 EXTRACT P_3 Last Started 2011-12-01 13:11 Status RUNNING Checkpoint Lag 00:00:00 (updated 00:00:00 ago) Log Read Checkpoint File /opt/OGG/dirdat/extract/A3000000 2011-12-02 08:50:15.000000 RBA 393705 --ext_3和p_3是目标端r_3的对应进程 #######################################################################
果然是系统时间错误,源端和目标端相差了近八个小时
二、更正目标端时间
[oracle@srtcreen dirdat]$ date Fri Dec 2 16:55:55 CST 2011 [oracle@srtcreen OGG]$ su - root Password: [root@srtcreen ~]# date -s 08:58:20 Fri Dec 2 08:58:20 CST [root@srtcreen ~]# clock -w [root@srtcreen ~]# date Fri Dec 2 08:58:28 CST [root@srtcreen ~]# su - oracle [oracle@srtcreen dirdat]$ ggsci Oracle GoldenGate Command Interpreter for Oracle Version 11.1.1.1.1 OGGCORE_11.1.1.1.1_PLATFORMS_110729.1700 Linux, x64, 64bit (optimized), Oracle 10g on Jul 29 2011 19:43:29 Copyright (C) 1995, 2011, Oracle and/or its affiliates. All rights reserved. GGSCI (srtcreen) 1> info all Program Status Group Lag Time Since Chkpt MANAGER RUNNING REPLICAT RUNNING R_1 00:00:00 unknown REPLICAT RUNNING R_2 00:00:00 unknown REPLICAT ABENDED R_3 19:19:34 unknown REPLICAT STOPPED R_4 00:00:00 11:54:31 REPLICAT STOPPED R_5 00:00:00 11:54:20 [oracle@srtcreen OGG]$ cd dirdat [oracle@srtcreen dirdat]$ ll total 412 -rw-rw-rw- 1 oracle oinstall 0 Dec 1 21:10 U1000000 -rw-rw-rw- 1 oracle oinstall 6485 Dec 2 2011 U2000000 -rw-rw-rw- 1 oracle oinstall 407519 Dec 2 09:04 U3000000
最新写到目标端的数据已经是当前修改时间(这个是系统时间,肯定会修改过来)
出现Time Since Chkpt unknown,处理方法见ogg中Time Since Chkpt显示unknown解决
三、重设r_3时间点
GGSCI (srtcreen) 7> alter r_3,begin 2011-12-02 09:00:00 REPLICAT altered. GGSCI (srtcreen) 9> start r_3 Sending START request to MANAGER ... REPLICAT R_3 starting GGSCI (srtcreen) 10> info all Program Status Group Lag Time Since Chkpt MANAGER RUNNING REPLICAT RUNNING R_1 00:00:00 00:00:05 REPLICAT RUNNING R_2 00:00:00 00:00:02 REPLICAT ABENDED R_3 unknown 00:00:00 REPLICAT STOPPED R_4 00:00:00 11:55:40 REPLICAT STOPPED R_5 00:00:00 11:55:29 GGSCI (srtcreen) 11> view report r_3 *********************************************************************** Oracle GoldenGate Delivery for Oracle Version 11.1.1.1.1 OGGCORE_11.1.1.1.1_PLATFORMS_110729.1700 Linux, x64, 64bit (optimized), Oracle 10g on Sep 13 2011 21:33:03 Copyright (C) 1995, 2011, Oracle and/or its affiliates. All rights reserved. Starting at 2011-12-02 09:09:31 *********************************************************************** Operating System Version: Linux Version #1 SMP Fri Apr 2 14:58:14 EDT 2010, Release 2.6.18-194.el5 Node: srtcreen Machine: x86_64 soft limit hard limit Address Space Size : unlimited unlimited Heap Size : unlimited unlimited File Size : unlimited unlimited CPU Time : unlimited unlimited Process id: 13629 Description: *********************************************************************** ** Running with the following parameters ** *********************************************************************** replicat r_3 ASSUMETARGETDEFS HANDLECOLLISIONS SETENV (NLS_LANG =AMERICAN_AMERICA.ZHS16GBK) Set environment variable (NLS_LANG=AMERICAN_AMERICA.ZHS16GBK) userid it1ogg, password ******** --file for dicarded transaction -- discardfile /opt/OGG/discard/R_3.txt, append, megabytes 100 DDL MAP CSCNEW.TAB_CS_CALL_PICKUP, TARGET SRT_CREEN.TAB_CS_CALL_PICKUP, KEYCOLS (CALL_ID); CACHEMGR virtual memory values (may have been adjusted) CACHEBUFFERSIZE: 64K CACHESIZE: 512M CACHEBUFFERSIZE (soft max): 4M CACHEPAGEOUTSIZE (normal): 4M PROCESS VM AVAIL FROM OS (min): 1G CACHESIZEMAX (strict force to disk): 881M Database Version: Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bi PL/SQL Release 10.2.0.4.0 - Production CORE 10.2.0.4.0 Production TNS for Linux: Version 10.2.0.4.0 - Production NLSRTL Version 10.2.0.4.0 - Production Database Language and Character Set: NLS_LANG = "AMERICAN_AMERICA.ZHS16GBK" NLS_LANGUAGE = "AMERICAN" NLS_TERRITORY = "AMERICA" NLS_CHARACTERSET = "ZHS16GBK" For further information on character set settings, please refer to user manual. *********************************************************************** ** Run Time Messages ** *********************************************************************** Opened trail file /opt/OGG/dirdat/U3000000 at 2011-12-02 09:09:32 MAP resolved (entry CSCNEW.TAB_CS_CALL_PICKUP): MAP CSCNEW.TAB_CS_CALL_PICKUP, TARGET SRT_CREEN.TAB_CS_CALL_PICKUP, KEYCOLS (CALL_ID); Using following columns in default map by name: PICKUP_ID, CALL_ID, CALL_SERIAL, USER_ID, PICKUP_TIME, CALL_RESULT, FAIL_REASON, CALL_TIME, CALL_DURA, END_TIME Using the following key columns for target table SRT_CREEN.TAB_CS_CALL_PICKUP: CALL_ID. 2011-12-02 09:09:32 WARNING OGG-00869 OCI Error ORA-01407: cannot update ("SRT_CREEN"."TAB_CS_CALL_PICKUP"."PICKUP_ID") to NULL (status = 1407), SQL <UPDAT E "SRT_CREEN"."TAB_CS_CALL_PICKUP" SET "PICKUP_ID" = :a0,"CALL_SERIAL" = :a2,"USER_ID" = :a3,"PICKUP_TIME" = :a4,"CALL_RESULT" = :a5,"FAIL_REASON" = :a6,"CAL L_TIME" = :a7,"CALL_DURA" = :a8,"END_T>. 2011-12-02 09:09:32 WARNING OGG-01004 Aborted grouped transaction on 'SRT_CREEN.TAB_CS_CALL_PICKUP', Database error 1407 (OCI Error ORA-01407: cannot updat e ("SRT_CREEN"."TAB_CS_CALL_PICKUP"."PICKUP_ID") to NULL (status = 1407), SQL <UPDATE "SRT_CREEN"."TAB_CS_CALL_PICKUP" SET "PICKUP_ID" = :a0,"CALL_SERIAL" = :a2,"USER_ID" = :a3,"PICKUP_TIME" = :a4,"CALL_RESULT" = :a5,"FAIL_REASON" = :a6,"CALL_TIME" = :a7,"CALL_DURA" = :a8,"END_T>). 2011-12-02 09:09:32 WARNING OGG-01003 Repositioning to rba 375833 in seqno 0. 2011-12-02 09:09:32 WARNING OGG-01154 SQL error 1407 mapping CSCNEW.TAB_CS_CALL_PICKUP to SRT_CREEN.TAB_CS_CALL_PICKUP OCI Error ORA-01407: cannot update ( "SRT_CREEN"."TAB_CS_CALL_PICKUP"."PICKUP_ID") to NULL (status = 1407), SQL <UPDATE "SRT_CREEN"."TAB_CS_CALL_PICKUP" SET "PICKUP_ID" = :a0,"CALL_SERIAL" = :a2 ,"USER_ID" = :a3,"PICKUP_TIME" = :a4,"CALL_RESULT" = :a5,"FAIL_REASON" = :a6,"CALL_TIME" = :a7,"CALL_DURA" = :a8,"END_T>. 2011-12-02 09:09:32 WARNING OGG-01003 Repositioning to rba 375833 in seqno 0. Source Context : SourceModule : [er.main] SourceID : [/scratch/angorant/view_storage/angorant_ogg_12978807_x64/oggcore/OpenSys/src/app/er/rep.c] SourceFunction : [take_rep_err_action] SourceLine : [16134] ThreadBacktrace : [8] elements : [/opt/OGG/replicat(CMessageContext::AddThreadContext()+0x26) [0x5ef8b6]] : [/opt/OGG/replicat(CMessageFactory::CreateMessage(CSourceContext*, unsigned int, ...)+0x7b2) [0x5e6382]] : [/opt/OGG/replicat(_MSG_ERR_MAP_TO_TANDEM_FAILED(CSourceContext*, DBString<777> const&, DBString<777> const&, CMessageFactory::Me ssageDisposition)+0x9b) [0x5c4bcb]] : [/opt/OGG/replicat [0x81ac2f]] : [/opt/OGG/replicat [0x8f73e2]] : [/opt/OGG/replicat(main+0x84b) [0x50764b]] : [/lib64/libc.so.6(__libc_start_main+0xf4) [0x3e2f41d994]] : [/opt/OGG/replicat(__gxx_personality_v0+0x1da) [0x4e3c2a]] 2011-12-02 09:09:32 ERROR OGG-01296 Error mapping from CSCNEW.TAB_CS_CALL_PICKUP to SRT_CREEN.TAB_CS_CALL_PICKUP. *********************************************************************** * ** Run Time Statistics ** * *********************************************************************** Last record for the last committed transaction is the following: ___________________________________________________________________ Trail name : /opt/OGG/dirdat/U3000000 Hdr-Ind : E (x45) Partition : . (x04) UndoFlag : . (x00) BeforeAfter: A (x41) RecLength : 157 (x009d) IO Time : 2011-12-02 11:52:49.559112 IOType : 15 (x0f) OrigNode : 255 (xff) TransInd : . (x03) FormatType : R (x52) SyskeyLen : 0 (x00) Incomplete : . (x00) AuditRBA : 3233 AuditPos : 8194064 Continued : N (x00) RecCount : 1 (x01) 2011-12-02 11:52:49.559112 FieldComp Len 157 RBA 375833 Name: CSCNEW.TAB_CS_CALL_PICKUP ___________________________________________________________________ Reading /opt/OGG/dirdat/U3000000, current RBA 375833, 0 records Report at 2011-12-02 09:09:32 (activity since 2011-12-02 09:09:32) From Table CSCNEW.TAB_CS_CALL_PICKUP to SRT_CREEN.TAB_CS_CALL_PICKUP: # inserts: 0 # updates: 0 # deletes: 0 # discards: 1 DDL replication statistics: Operations: 0 Mapped operations: 0 Unmapped operations: 0 Other operations: 0 Excluded operations: 0 Errors: 0 Retried errors: 0 Discarded errors: 0 Ignored errors: 0 Last log location read: FILE: /opt/OGG/dirdat/U3000000 SEQNO: 0 RBA: 375833 TIMESTAMP: 2011-12-02 11:52:49.559112 EOF: NO READERR: 0 2011-12-02 09:09:32 ERROR OGG-01668 PROCESS ABENDING. --这里可以看出我重设的当前的时间点对应的io time为2011-12-02 11:52:49.559112,而现在尚未到这个时间,进程启动失败 GGSCI (srtcreen) 2> alter r_3,begin 2011-12-02 18:00:00 REPLICAT altered. --重设时间到今天早上我重设时间之前的错误时间之后 GGSCI (srtcreen) 3> start r_3 Sending START request to MANAGER ... REPLICAT R_3 starting GGSCI (srtcreen) 4> info all Program Status Group Lag Time Since Chkpt MANAGER RUNNING REPLICAT RUNNING R_1 00:00:00 00:00:06 REPLICAT RUNNING R_2 00:00:00 00:00:01 REPLICAT RUNNING R_3 unknown 00:00:08 REPLICAT RUNNING R_4 00:00:00 00:00:09 REPLICAT RUNNING R_5 00:00:00 00:00:09 GGSCI (srtcreen) 5> info all Program Status Group Lag Time Since Chkpt MANAGER RUNNING REPLICAT RUNNING R_1 00:00:00 00:00:09 REPLICAT RUNNING R_2 00:00:00 00:00:03 REPLICAT RUNNING R_3 00:00:00 00:00:00 REPLICAT RUNNING R_4 00:00:00 00:00:02 REPLICAT RUNNING R_5 00:00:00 00:00:01 GGSCI (srtcreen) 6> stats r_3 Sending STATS request to REPLICAT R_3 ... No active replication maps DDL replication statistics: *** Total statistics since replicat started *** Operations 0.00 Mapped operations 0.00 Unmapped operations 0.00 Other operations 0.00 Excluded operations 0.00 Errors 0.00 Retried errors 0.00 Discarded errors 0.00 Ignored errors 0.00 --进程启动,工作正常
三、补充说明
1、部署ogg前需要核对两边时间是否相同,为了避免不必要的麻烦,建议配置ntp同步时间
2、这里因为我们这要求该同步上线无严格时间要求,所以通过重设r_3时间点实现工作正常,如果事情比较紧急,建议删除trail文件,重建pump和replicat进程
3、这里说明ogg同步也还不是和时间一点关系都没有
这个问题会多多注意。