Apply Mode in Goldengate

talio發表於2013-08-28

In Goldengate, when replicat process apply sql statements in target database, there are three apply modes,they are: normal mode,batchsql mode and source mode.This post is aiming at:

  1. Introducing these three apply modes, explaining the difference among them;
  2. Introducing the switch over among different apply mode;

Firstly,let`s have a look at what are these three apply modes meaning respectively.

Normal mode:In normal mode, Replicat accumulates operations from source transactions, in transaction order, and applies them as a group within one transaction on the target.

Batchsql mode: In batchsql mode, replicat organizes similar SQL statements into batches within a memory queue, and then it applies each batch in one database operation. A batch contains sql statements that affect the same table, operation type (insert, update, or delete), and column list.

Source mode:in source mode, as the name telling us, replicat process apply sql statements the same as it did on source db side.


In official document <>, oracle explained the difference among the three apply mode briefly in figure 14. like below:

Source Transactions

(Assumes same table and column list)

Replication Transactions(normal mode) Replication Transactions(batchsql mode) Replication Transactions(source mode)

transaction 1:insert/delete

Transaction:

insert/delete/insert/delete/insert/delete

Transaction:

insert(x3)

delete(x3)

transaction 1:insert/delete
transaction 2:insert/delete transaction 2:insert/delete
transaction 3:insert/delete transaction 3:insert/delete


In this post, I`ll explain it more detailed base on testing. Let`s begin.

Creating test table on source and target database:

conn gg_test/gg_test

create table TEST_APPLY_MODE as select * from user_objects where 0=1;

alter table TEST_APPLY_MODE add constraint pk_test_apply_mode primary key(object_id);

alter table TEST_APPLY_MODE add constraint uk_test_apply_mode unique(data_object_id);

 

Then set up goldengate replication program *_TEST01 to replicat table GG_TEST.TEST_APPLY_MODE from source db to target db.

In this testing,we use goldengate trace and database statistics info to help check what we want.

On target side, enable the replicat trace with following statement:

send replicat R_TEST01 trace test01_trace.log

This trace can be closed with command:  send replicat R_TEST01 trace off.

At database level, we need check database statistics also, like ‘user commits’.


Firstly, let`s begin with normal mode.

Normal Mode

Normal mode is the default mode when goldengate apply transactions, if we don`t add ‘batchsql’ parameter in replicat program configuration, then oracle will use normal mode to apply transaction by default.

On target database, checking ‘user commits’ stats before apply transaction on CNR database, it is 19:

select a.name,p.spid,ss.value

from v$statname a,v$process p,v$session s,v$sesstat ss

where a.name='user commits' and p.addr=s.paddr and ss.sid=s.sid and a.statistic#=ss.statistic# and p.spid=13786;  --13786 is the os process id of replicat process which connecting to database

NAME                                                             SPID              VALUE

---------------------------------------------------------------- ------------ ----------

user commits                                                     13786                 19

Then, execute following three transactions on source side:

conn gg_test/gg_test

--transaction 1:

insert into TEST_APPLY_MODE(OBJECT_ID,OBJECT_NAME) values(1,'a');

update TEST_APPLY_MODE set OBJECT_NAME='a1' where object_id=1;

commit;

--transaction 2:

insert into TEST_APPLY_MODE(OBJECT_ID,OBJECT_NAME) values(2,'b');

update TEST_APPLY_MODE set OBJECT_NAME='b2' where object_id=2;

commit;

--transaction 3:

insert into TEST_APPLY_MODE(OBJECT_ID,OBJECT_NAME) values(3,'c');

update TEST_APPLY_MODE set OBJECT_NAME='c3' where object_id=3;

commit;

 

Checking the replicat trace file test01_trace.log:

09:05:28.739 (2623328) processing record for GG_TEST.TEST_APPLY_MODE

09:05:28.739 (2623328) mapping record

09:05:28.739 (2623328) entering perform_sql_statements (normal)

09:05:28.739 (2623328) iotype:5 mode:0          --insert(1,a)

09:05:28.739 (2623328) BIND val for col:0  :61 0

09:05:28.739 (2623328) BIND val for col:1  : 0 0

09:05:28.739 (2623328) BIND val for col:2  :31 0

09:05:28.739 (2623328) BIND val for col:3  : 0 0

09:05:28.739 (2623328) BIND val for col:4  : 0 0

09:05:28.739 (2623328) BIND val for col:5  : 0 0

09:05:28.739 (2623328) BIND val for col:6  : 0 0

09:05:28.739 (2623328) BIND val for col:7  : 0 0

09:05:28.739 (2623328) BIND val for col:8  : 0 0

09:05:28.739 (2623328) BIND val for col:9  : 0 0

09:05:28.739 (2623328) BIND val for col:10  : 0 0

09:05:28.739 (2623328) BIND val for col:11  : 0 0

09:05:28.739 (2623328) OCI statement executed successfully...

09:05:28.739 (2623328) exited perform_sql_statements (sql_err=0,recs utput=65)

09:05:28.739 (2623328) * --- entering READ_EXTRACT_RECORD --- *

09:05:28.739 (2623328) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=13595)

09:05:28.739 (2623328) processing record for GG_TEST.TEST_APPLY_MODE

09:05:28.739 (2623328) mapping record

09:05:28.739 (2623328) entering perform_sql_statements (normal)

09:05:28.739 (2623328) iotype:15 mode:0       --update(object_id=1)

09:05:28.739 (2623328) BIND val for col:0  :61 31

09:05:28.739 (2623328) BIND val for col:2 :31 0 len:1 blen:0

09:05:28.739 (2623328) OCI statement executed successfully...

09:05:28.739 (2623328) exited perform_sql_statements (sql_err=0,recs utput=66)

09:05:28.739 (2623328) * --- entering READ_EXTRACT_RECORD --- *

09:05:28.739 (2623328) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=13709)

09:05:28.739 (2623328) processing record for GG_TEST.TEST_APPLY_MODE

09:05:28.739 (2623328) mapping record

09:05:28.839 (2623428) entering perform_sql_statements (normal)

09:05:28.839 (2623428) iotype:5 mode:0          --insert(2,b)

09:05:28.839 (2623428) BIND val for col:0  :62 0

09:05:28.839 (2623428) BIND val for col:1  : 0 0

09:05:28.839 (2623428) BIND val for col:2  :32 0

09:05:28.839 (2623428) BIND val for col:3  : 0 0

09:05:28.839 (2623428) BIND val for col:4  : 0 0

09:05:28.839 (2623428) BIND val for col:5  : 0 0

09:05:28.839 (2623428) BIND val for col:6  : 0 0

09:05:28.839 (2623428) BIND val for col:7  : 0 0

09:05:28.839 (2623428) BIND val for col:8  : 0 0

09:05:28.839 (2623428) BIND val for col:9  : 0 0

09:05:28.839 (2623428) BIND val for col:10  : 0 0

09:05:28.839 (2623428) BIND val for col:11  : 0 0

09:05:28.839 (2623428) OCI statement executed successfully...

09:05:28.839 (2623428) exited perform_sql_statements (sql_err=0,recs utput=67)

09:05:28.839 (2623428) * --- entering READ_EXTRACT_RECORD --- *

09:05:28.839 (2623428) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=13970)

09:05:28.839 (2623428) processing record for GG_TEST.TEST_APPLY_MODE

09:05:28.839 (2623428) mapping record

09:05:28.839 (2623428) entering perform_sql_statements (normal)

09:05:28.839 (2623428) iotype:15 mode:0        --update(object_id=2)

09:05:28.839 (2623428) BIND val for col:0  :62 32

09:05:28.839 (2623428) BIND val for col:2 :32 0 len:1 blen:0

09:05:28.839 (2623428) OCI statement executed successfully...

09:05:28.839 (2623428) exited perform_sql_statements (sql_err=0,recs utput=68)

09:05:28.839 (2623428) * --- entering READ_EXTRACT_RECORD --- *

09:05:28.839 (2623428) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=14084)

09:05:28.839 (2623428) processing record for GG_TEST.TEST_APPLY_MODE

09:05:28.839 (2623428) mapping record

09:05:28.839 (2623428) entering perform_sql_statements (normal)

09:05:28.839 (2623428) iotype:5 mode:0          --insert(3,c)

09:05:28.839 (2623428) BIND val for col:0  :63 0

09:05:28.839 (2623428) BIND val for col:1  : 0 0

09:05:28.839 (2623428) BIND val for col:2  :33 0

09:05:28.839 (2623428) BIND val for col:3  : 0 0

09:05:28.839 (2623428) BIND val for col:4  : 0 0

09:05:28.839 (2623428) BIND val for col:5  : 0 0

09:05:28.839 (2623428) BIND val for col:6  : 0 0

09:05:28.839 (2623428) BIND val for col:7  : 0 0

09:05:28.839 (2623428) BIND val for col:8  : 0 0

09:05:28.839 (2623428) BIND val for col:9  : 0 0

09:05:28.839 (2623428) BIND val for col:10  : 0 0

09:05:28.839 (2623428) BIND val for col:11  : 0 0

09:05:28.839 (2623428) OCI statement executed successfully...

09:05:28.849 (2623438) exited perform_sql_statements (sql_err=0,recs utput=69)

09:05:28.849 (2623438) * --- entering READ_EXTRACT_RECORD --- *

09:05:28.849 (2623438) exited READ_EXTRACT_RECORD (stat=0, seqno=0, rba=14344)

09:05:28.849 (2623438) processing record for GG_TEST.TEST_APPLY_MODE

09:05:28.849 (2623438) mapping record

09:05:28.849 (2623438) entering perform_sql_statements (normal)

09:05:28.849 (2623438) iotype:15 mode:0        --update(object_id=3)

09:05:28.849 (2623438) BIND val for col:0  :63 33

09:05:28.849 (2623438) BIND val for col:2 :33 0 len:1 blen:0

09:05:28.849 (2623438) OCI statement executed successfully...

09:05:28.849 (2623438) exited perform_sql_statements (sql_err=0,recs utput=70)

09:05:28.849 (2623438) * --- entering READ_EXTRACT_RECORD --- *

09:05:28.849 (2623438) exited READ_EXTRACT_RECORD (stat=400, seqno=0, rba=14458)

09:05:28.849 (2623438) committing work             --commit transaction

09:05:28.849 (2623438) writing database checkpoint

09:05:28.849 (2623438) executing OCITransCommit...

09:05:28.849 (2623438) executed OCITransCommit...

09:05:28.849 (2623438) work committed

 

From above replicat trace file, in normal mode, replicat organize DML operations by source order into a group within one transaction. This can also be confirmed by checking database ‘user commits’ statistics.

select a.name,p.spid,ss.value

from v$statname a,v$process p,v$session s,v$sesstat ss

where a.name='user commits' and p.addr=s.paddr and ss.sid=s.sid and a.statistic#=ss.statistic# and p.spid=13786; 

NAME                                                             SPID              VALUE

---------------------------------------------------------------- ------------ ----------

user commits                                                     13786                 20         --‘user commit’ counter is 20 now

 

As we saw in above test case, normal mode in fact is ‘group mode’, replicat accumulates operations from source transactions, in transaction order, and applies them as a group. At this point, you may ask:

Since replicat accumulate operations into group, how does oracle control the group size? 

The answer of this question is: goldengate control group size with parameter GROUPTRANSOPS.

From goldengate official document,”replicat use the GROUPTRANSOPS parameter to control the number of SQL operations that are contained in a replicat transaction when operating in its normal mode”. The default value of this parameter is 1000. Please be noted the GROUPTRANSOPS parameter sets a minimum value rather than an absolute value, to avoid splitting apart source transactions. For example, if transaction A contains 500 operations and transaction B contains 600, the Replicat transaction will contain all 1,100 operations even though GROUPTRANSOPS is set to the default value of 1,000.

Now we know parameter GROUPTRANSOPS, then another question comes:

If a transaction doesn`t reach the size set by GROUPTRANSOPS and there is no more data in the trail to process, when will replicat apply it?

Let`s check the trace file again:

grep -i 'committing work' test01_trace.log|more

09:04:18.575 (2553164) committing work

09:04:28.599 (2563187) committing work

09:04:28.709 (2563297) committing work

09:04:39.633 (2574321) committing work

09:04:50.656 (2585245) committing work

09:05:00.769 (2595358) committing work

09:05:08.792 (2603381) committing work

09:05:19.816 (2614404) committing work

09:05:28.849 (2623438) committing work

09:05:39.774 (2634462) committing work

09:05:50.797 (2645386) committing work

09:06:00.822 (2655410) committing work

09:06:10.835 (2665424) committing work

09:06:21.859 (2676448) committing work

……

view test01_trace.log

…….

09:04:28.599 (2563187) committing work

09:04:28.599 (2563187) writing database checkpoint

09:04:28.599 (2563187) executing OCITransCommit...

09:04:28.599 (2563187) executed OCITransCommit...

09:04:28.599 (2563187) work committed

09:04:28.599 (2563187) writing checkpoint

……

 

From the trace info, we found, goldengate is doing a scheduled checkpoint work at an interval of 10 seconds. During the checkpoint,if a transaction group found, even if a group operations doesn`t reach to GROUPTRANSOPS, it will commit it also, and the prerequisite is not splitting source transaction.


Now, let`s check batchsql mode.

BATCHSQL Mode

To enable batchsql mode, we need add parameter ‘BATCHSQL’ into replicat configuration.

Then,let`s repeat the same testing in batchsql mode(we already deleted all inserted rows in previous testing):

-- On Source db

conn gg_test/gg_test

--transaction 1:

insert into TEST_APPLY_MODE(OBJECT_ID,OBJECT_NAME) values(1,'a');

update TEST_APPLY_MODE set OBJECT_NAME='a1' where object_id=1;

commit;

--transaction 2:

insert into TEST_APPLY_MODE(OBJECT_ID,OBJECT_NAME) values(2,'b');

update TEST_APPLY_MODE set OBJECT_NAME='b2' where object_id=2;

commit;

--transaction 3:

insert into TEST_APPLY_MODE(OBJECT_ID,OBJECT_NAME) values(3,'c');

update TEST_APPLY_MODE set OBJECT_NAME='c3' where object_id=3;

commit;

 

Checking the replicat trace:

05:56:12.455 (687705306) * --- entering READ_EXTRACT_RECORD --- *

05:56:12.455 (687705306) exited READ_EXTRACT_RECORD (stat=0, seqno=105, rba=98926952)

05:56:12.455 (687705306) processing record for GG_TEST.TEST_APPLY_MODE

05:56:12.455 (687705306) mapping record

05:56:12.455 (687705306) entering perform_sql_statements (normal)

05:56:12.455 (687705306) exited perform_sql_statements (sql_err=0,recs utput=3540769)

05:56:12.455 (687705306) * --- entering READ_EXTRACT_RECORD --- *

05:56:12.455 (687705306) exited READ_EXTRACT_RECORD (stat=0, seqno=105, rba=98927066)

05:56:12.455 (687705306) processing record for GG_TEST.TEST_APPLY_MODE

05:56:12.455 (687705306) mapping record

05:56:12.455 (687705306) entering perform_sql_statements (normal)

05:56:12.455 (687705306) exited perform_sql_statements (sql_err=0,recs utput=3540770)

05:56:12.455 (687705306) * --- entering READ_EXTRACT_RECORD --- *

05:56:12.455 (687705306) exited READ_EXTRACT_RECORD (stat=0, seqno=105, rba=98927325)

05:56:12.455 (687705306) processing record for GG_TEST.TEST_APPLY_MODE

05:56:12.455 (687705306) mapping record

05:56:12.455 (687705306) entering perform_sql_statements (normal)

05:56:12.455 (687705306) exited perform_sql_statements (sql_err=0,recs utput=3540771)

05:56:12.455 (687705306) * --- entering READ_EXTRACT_RECORD --- *

05:56:12.455 (687705306) exited READ_EXTRACT_RECORD (stat=0, seqno=105, rba=98927439)

05:56:12.455 (687705306) processing record for GG_TEST.TEST_APPLY_MODE

05:56:12.455 (687705306) mapping record

05:56:12.455 (687705306) entering perform_sql_statements (normal)

05:56:12.455 (687705306) exited perform_sql_statements (sql_err=0,recs utput=3540772)

05:56:12.455 (687705306) * --- entering READ_EXTRACT_RECORD --- *

05:56:12.455 (687705306) exited READ_EXTRACT_RECORD (stat=0, seqno=105, rba=98927699)

05:56:12.455 (687705306) processing record for GG_TEST.TEST_APPLY_MODE

05:56:12.455 (687705306) mapping record

05:56:12.455 (687705306) entering perform_sql_statements (normal)

05:56:12.455 (687705306) exited perform_sql_statements (sql_err=0,recs utput=3540773)

05:56:12.455 (687705306) * --- entering READ_EXTRACT_RECORD --- *

05:56:12.455 (687705306) exited READ_EXTRACT_RECORD (stat=400, seqno=105, rba=98927813)

05:56:12.455 (687705306) committing work

05:56:12.455 (687705306) CDR io type:5  mode:0

05:56:12.455 (687705306) iotype:5 mode:0

05:56:12.455 (687705306) BIND val for col:0  :61 0                --insert(1,a)

05:56:12.455 (687705306) BIND val for col:1  :36 37

05:56:12.455 (687705306) BIND val for col:2  :31 0

05:56:12.455 (687705306) BIND val for col:3  : 0 33

05:56:12.455 (687705306) BIND val for col:4  :30 31

05:56:12.455 (687705306) BIND val for col:5  : 0 35

05:56:12.455 (687705306) BIND val for col:6  : 0 0

05:56:12.455 (687705306) BIND val for col:7  :30 35

05:56:12.455 (687705306) BIND val for col:8  :36 33

05:56:12.455 (687705306) BIND val for col:9  :30 34

05:56:12.455 (687705306) BIND val for col:10  :36 32

05:56:12.455 (687705306) BIND val for col:11  : 0 30

05:56:12.455 (687705306) BIND val for col:0  :62 33                 --insert(2,b)

05:56:12.455 (687705306) BIND val for col:1  :32 32

05:56:12.455 (687705306) BIND val for col:2  :32 0

05:56:12.455 (687705306) BIND val for col:3  : 0 30

05:56:12.455 (687705306) BIND val for col:4  :30 31

05:56:12.455 (687705306) BIND val for col:5  : 0 30

05:56:12.455 (687705306) BIND val for col:6  : 0 33

05:56:12.455 (687705306) BIND val for col:7  :37 35

05:56:12.455 (687705306) BIND val for col:8  :35 35

05:56:12.455 (687705306) BIND val for col:9  :34 37

05:56:12.455 (687705306) BIND val for col:10  :32 36

05:56:12.455 (687705306) BIND val for col:11  :30 33

05:56:12.455 (687705306) BIND val for col:0  :63 30                   --insert(3,c)

05:56:12.455 (687705306) BIND val for col:1  : 0 38

05:56:12.455 (687705306) BIND val for col:2  :33 0

05:56:12.455 (687705306) BIND val for col:3  : 0 32

05:56:12.455 (687705306) BIND val for col:4  :30 31

05:56:12.455 (687705306) BIND val for col:5  : 0 32

05:56:12.455 (687705306) BIND val for col:6  : 0 35

05:56:12.455 (687705306) BIND val for col:7  :34 35

05:56:12.455 (687705306) BIND val for col:8  :36 31

05:56:12.455 (687705306) BIND val for col:9  :37 31

05:56:12.455 (687705306) BIND val for col:10  :36 37

05:56:12.455 (687705306) BIND val for col:11  :33 0

05:56:12.585 (687705436) OCI statement executed successfully...

05:56:12.585 (687705436) CDR io type:15  mode:0

05:56:12.585 (687705436) iotype:15 mode:0

05:56:12.585 (687705436) BIND val for col:0  :61 31                 --update(object_id=1)

05:56:12.585 (687705436) BIND val for col:2 :31 0 len:1 blen:0

05:56:12.585 (687705436) BIND val for col:0  :62 32                 --update(object_id=2)

05:56:12.585 (687705436) BIND val for col:2 :32 0 len:1 blen:0

05:56:12.585 (687705436) BIND val for col:0  :63 33                 --update(object_id=3)

05:56:12.585 (687705436) BIND val for col:2 :33 0 len:1 blen:0

05:56:12.615 (687705466) OCI statement executed successfully...

05:56:12.615 (687705466) writing database checkpoint

05:56:12.625 (687705476) executing OCITransCommit...               --commit transaction   

05:56:12.625 (687705476) executed OCITransCommit...

05:56:12.625 (687705476) work committed

 

From above trace,we found, replicat put three similar insert operations together into a array, and insert them in one batch, although they were locating in different transaction in source. And apply three similar updates in one batch also,both of the two batches are committed in one transaction. batchsql mode in fact is ‘array mode’.

When Replicat is in BATCHSQL mode, smaller row changes will show a higher gain in performance than larger row changes. The cost of using batchsql mode is memory consumption, for goldengate need use memory queue to organize similar sql statement.


To manage BATCHSQL mode, goldengate provides a series of BATCHSQL options. Such as:

BATCHESPERQUEUE: Controls the maximum number of batches that one memory queue can contain.

BATCHTRANSOPS: Controls the maximum number of batch operations that can be grouped into a transaction before requiring a commit.

BYTESPERQUEUE: Controls the maximum number of batch operations that can be grouped into a transaction before requiring a commit.

There are also some other options, I didn`t list them all. To get more, please refer to goldengate official document.

We can get a batchsql running statistics with command: send r_dse01,report. after running it, we can check batchsql statistics in report file ./dirrpt/R_TEST01.rpt.

BATCHSQL statistics:

              Batch operations:  20128291

                       Batches:   1698633

              Batches executed:   1723817

                        Queues:    468364

              Batches in error:         1

        Normal mode operations:       404

    Immediate flush operations:         0

                 PK collisions:   2680954

                 UK collisions:         0

                 FK collisions:         0

           Thread batch groups:         0

                       Commits:     43732

                     Rollbacks:         1

             Queue flush calls:     38281

                 Ops per batch:     11.85

        Ops per batch executed:     11.68

                 Ops per queue:     42.98

           Parallel batch rate:       N/A

 


Source Mode

In source mode, replicat apply sql statements by the source transaction order, and doesn`t change the original transaction boundaries. It`s easy to understand, so I didn`t repeat previous testing in this mode.

When will goldengate use source mode?

In previous description,we have known how to set batchsql mode or normal mode, but how we choose source mode?

In fact, this is choosen by goldengate itself. To answer the question ‘when’, we need talk about the apply mode switch over.

Assuming we are using BATCHSQL mode,when replicat encounters exceptions in batch mode, it rolls back the batch operation and then tries to apply the exceptions in the following ways, always maintaining transaction integrity:

  • First Replicat tries to use normal mode: one SQL statement at a time within the transaction boundaries that are set with the GROUPTRANSOPS parameter.
  • If normal mode fails also, Replicat tries to use source mode: apply the SQL within the same transaction boundaries that were used on the source.

When finished processing exceptions, Replicat resumes BATCHSQL mode.

From the switch over mechanism, we know when will goldengate choose source mode. Source mode is more like an exception solution.


Finally, I did a test case to show the switch over among the three apply mode.

Apply Mode Switch Over

On target db, set replicat r_test01 into batchsql mode:

--view params R_TEST01

REPLICAT R_TEST01

USERID ggs_owner, PASSWORD ***

Assumetargetdefs

BATCHSQL

DISCARDFILE ***/dirrpt/record01.dsc,APPEND,MEGABYTES 50

MAP GG_TEST.TEST_APPLY_MODE,                 TARGET GG_TEST.TEST_APPLY_MODE                ;


Then, on source side, apply following three transactions.

--transaction 1

insert into TEST_APPLY_MODE(OBJECT_ID,DATA_OBJECT_ID,OBJECT_NAME) values(1,1,'a');

update TEST_APPLY_MODE set OBJECT_NAME='a1' where object_id=1;

commit;

--transaction 2

insert into TEST_APPLY_MODE(OBJECT_ID,DATA_OBJECT_ID,OBJECT_NAME) values(2,2,'b');

update TEST_APPLY_MODE set OBJECT_NAME='b2' where object_id=2;

commit;

--transaction 3

update TEST_APPLY_MODE set DATA_OBJECT_ID=DATA_OBJECT_ID+1;

commit;

 

In this testing,transaction 3 can be applied well on source, but will failed on target db, for the update operation on source will update two rows,but on target db, oracle will divide it into two separate update statements, then it will fail for “unique constraint violated”.

Let`s check the event log on target server.

2013-06-03 01:17:55  WARNING OGG-00869  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  Aborting BATCHSQL transaction. Database error 1 (ORA-00001: unique constraint (GG_TEST.UK_CONS_TEST_APPLY_MODE) violated).

2013-06-03 01:17:55  WARNING OGG-01137  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  BATCHSQL suspended, continuing in normal mode.

2013-06-03 01:17:55  WARNING OGG-01003  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  Repositioning to rba 14803 in seqno 0.

2013-06-03 01:17:55  WARNING OGG-00869  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  OCI Error ORA-00001: unique constraint (GG_TEST.UK_CONS_TEST_APPLY_MODE) violated (status= 1). UPDATE "GG_TEST"."TEST_APPLY_MODE" SET "DATA_OBJECT_ID" = :a1 WHERE "OBJECT_ID" = :b0.

2013-06-03 01:17:55  WARNING OGG-01004  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  Aborted grouped transaction on 'GG_TEST.TEST_APPLY_MODE', Database error 1 (OCI Error ORA-00001: unique constraint (GG_TEST.UK_CONS_TEST_APPLY_MODE) violated (status = 1). UPDATE "GG_TEST"."TEST_APPLY_MODE" SET "DATA_OBJECT_ID" = :a1 WHERE "OBJECT_ID" = :b0).

2013-06-03 01:17:55  WARNING OGG-01003  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  Repositioning to rba 14803 in seqno 0.

2013-06-03 01:17:55  WARNING OGG-01154  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  SQL error 1 mapping GG_TEST.TEST_APPLY_MODE to GG_TEST.TEST_APPLY_MODE OCI Error ORA-00001: unique constraint (GG_TEST.UK_CONS_TEST_APPLY_MODE) violated (status = 1). UPDATE "GG_TEST"."TEST_APPLY_MODE" SET "DATA_OBJECT_ID" = :a1 WHERE "OBJECT_ID" = :b0.

2013-06-03 01:17:55  WARNING OGG-01003  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  Repositioning to rba 15553 in seqno 0.

2013-06-03 01:17:55  ERROR   OGG-01296  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  Error mapping from GG_TEST.TEST_APPLY_MODE to GG_TEST.TEST_APPLY_MODE.

2013-06-03 01:17:55  ERROR   OGG-01668  Oracle GoldenGate Delivery for Oracle, r_test01.prm:  PROCESS ABENDING.

 

From the event log, we see:

  1. At the beginning,replicat r_test01 is working in BATCHSQL mode, when it encounteer database error ORA-00001, it switched to normal mode;
  2. In normal mode,replicat still see the same error, so it aborted group transaction, this means it aborted normal mode,then go into source mode;
  3. If in source mode, replicat still can`t process this transaction, then it abended replicat process.

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/27243841/viewspace-769414/,如需轉載,請註明出處,否則將追究法律責任。