一、错误检查
[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
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
: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
,"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
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
: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
,"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同步也还不是和时间一点关系都没有