Oracle DBA – A lifelong learning experience

GoldenGate – Restarting a replicat with the command filterduptransactions

Posted by John Hallas on April 4, 2017

If a Goldengate replicat process fails then occasionally on the restart it skips the correct RBA and ‘loses it’s position’. The relative byte address (RBA) is the location within the trail file to indicate the current transaction.

The old school method was to calculate which RBA was the correct one and then restart the replicat. However there is a new command on the block now (pun intended) and I will demonstrate how the two methods can be used to restart the trail file correctly

Today, we saw the following in the GG log file:
PS sorry if the format is a bit off. I normally spend me as much time formatting this blog as it I do writing it. However in this case much of the work was done by Alex Priestley – a fellow DBA

 
2017-04-03 14:56:05  ERROR   OGG-01705  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  Input checkpoint position 775267 for input trail file ‘./dirdat/R1WMP989/wm002970’ is greater than the size of the file (684968).  Please consult Oracle Knowledge Management Doc ID 1138409.1. for instructions.
2017-04-03 14:56:05  ERROR   OGG-01668  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  PROCESS ABENDING.
The ​old school method for fixing this is to walk through trail file and work out where the new data starts:
Using above example, the trail file is wm002970, therefore the next file is wm002971. Follow these commands (n goes to the next record):
Logdump 1 >open ./dirdat/R1WMP989/wm002971
Current LogTrail is /data/gg_shared/mdwprd2/dirdat/R1WMP989/wm002971

Logdump 2 >ghdr on
Logdump 3 >ggstoken detail
Logdump 4 >detail data on
Logdump 5 >n

2017/04/03 11:37:36.724.772 FileHeader           Len  1165 RBA 0

Name: *FileHeader*

 3000 0218 3000 0008 4747 0d0a 544c 0a0d 3100 0002 | 0…0…GG..TL..1…
 0003 3200 0004 2000 0000 3300 0008 02f2 7274 3429 | ..2... ...3.....rt4)
 3b24 3400 0037 0035 7572 693a 7077 7766 3031 6178 | ;$4..7.5uri:XXXXXXXX
 3a3a 6170 703a 676f 6c64 656e 6761 7465 3a50 3039 | ::app:goldengate:P09
 3839 5731 413a 3131 3231 3137 3a50 3157 4d50 3938 | 89W1A:112117:P1WMP98
 3935 0000 3b35 0000 3700 3575 7269 3a70 7777 6630 | 95..;5..7.5uri:XXXXX
 3161 783a 3a61 7070 3a67 6f6c 6465 6e67 6174 653a | XXX::app:goldengate:

Logdump 6 >n
___________________________________________________________________

Hdr-Ind    :     E  (x45)     Partition  :     .  (x00)
UndoFlag   :     .  (x00)     BeforeAfter:     A  (x41)
RecLength  :     0  (x0000)   IO Time    : 2017/04/03 11:37:36.511.369
IOType     :   150  (x96)     OrigNode   :     0  (x00)
TransInd   :     .  (x03)     FormatType :     R  (x52)
SyskeyLen  :     0  (x00)     Incomplete :     .  (x00)
AuditRBA   :          0       AuditPos   : 0
Continued  :     N  (x00)     RecCount   :     0  (x00)
2017/04/03 11:37:36.511.369 RestartAbend         Len     0 RBA 1173

Name:
After  Image:                                             Partition 0   G  s
GGS tokens:

TokenID x4e ‘N’ GROUPNAME        Info x00  Length    8

 5031 574d 5039 3839                               | P1WMP989

Logdump 7 >n
___________________________________________________________________

Hdr-Ind    :     E  (x45)     Partition  :     .  (x04)
UndoFlag   :     .  (x00)     BeforeAfter:     A  (x41)
RecLength  :   149  (x0095)   IO Time    : 2017/04/03 11:24:01.015.867
IOType     :     5  (x05)     OrigNode   :   255  (xff)
TransInd   :     .  (x03)     FormatType :     R  (x52)
SyskeyLen  :     0  (x00)     Incomplete :     .  (x00)
AuditRBA   :      93051       AuditPos   : 132419600
Continued  :     N  (x00)     RecCount   :     1  (x01)

2017/04/03 11:24:01.015.867 Insert               Len   149 RBA 1236
Name: WMS0989.LABOR_PRODUCTIVITY
After  Image:                                             Partition 4   G  s

 5e50 86ba af70 962b d652 5bf9 a36b 9760 5cbb 2f48 | ^P…p.+.R[..k.`\./H
 8ca5 2e9e b893 05d9 3a12 e06f 02db d398 2c88 3d83 | ........:..o....,.=.
 8946 e173 4380 e6ec 13b0 cd67 0457 b393 a085 e1c5 | .F.sC......g.W......
 f09d 9043 bb7d 3b68 138a 6631 8aea 2447 cceb 83dd | ...C.};h..f1..$G....
 b40e 2510 1e8c de36 d0dc 8d9b 90a5 6d43 9f84 99a8 | ..%....6......mC....
 6347 a79c 7cdb 783b 5f61 919d 4177 4ba0 6187 5c86 | cG..|.x;_a..AwK.a.\.
 655b c1a3 f797 607e 7a9e 769b 64ac bb77 e444 99a9 | e[....`~z.v.d..w.D..
Bad compressed block, found length of 34490 (x86ba), RBA 1236

GGS tokens:

TokenID x52 ‘R’ ORAROWID         Info x00  Length   20
 4141 4165 536c 4141 4141 4142 4768 2f41 4147 0001 | AAAeSlAAAAABGh/AAG..
TokenID x4c 'L' LOGCSN           Info x00  Length   14
 3131 3036 3030 3539 3338 3835 3536                | 11060059388556
TokenID x36 '6' TRANID           Info x00  Length   14
 3131 362e 3137 2e34 3837 3237 3739                | 116.17.4872779

Logdump 8 >exit
You can see the green is where the first new record is, as there is an insert statement on a table.
This is at RBA 1236.
Now, we have enough info to perform a calculation:  Note that the values for ‘a’ and ‘b’ can be found in the error message and I have highlighted them in red
Input checkpoint position:         775267 (a)
Size of file:                                    684968 (b)
1st valid record in next file:            1236 (c)
a-b+c=                                               91535
So, to restart, issue:

alter replicat R1WMP989, extseqno 2971, extrba 91535;

 

​As I said earlier, this is old school, and we can now just issue:

start R1WMP953 filterduptransactions

​Which we did. In the log file, we can see the following, which proves the new method skipped duplicate transactions, then started at around the same RBA (though disappointingly not exactly at 91535):
 
2017-04-03 14:57:31  INFO    OGG-00996  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  REPLICAT R1WMP989 started.
2017-04-03 14:57:34  INFO    OGG-01020  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  Processed extract process RESTART_ABEND record at seq 2971, rba 1173 (aborted 0 records).
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 1236, with CSN 11060059388556 and transaction ID 116.17.4872779.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 1526, with CSN 11060059388563 and transaction ID 45.0.27279964.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 2600, with CSN 11060059388570 and transaction ID 10.27.10908465.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 3094, with CSN 11060059388572 and transaction ID 7.6.15267654.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 3507, with CSN 11060059388677 and transaction ID 45.31.27289005.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 8074, with CSN 11060059388688 and transaction ID 45.3.27275193.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 12635, with CSN 11060059388692 and transaction ID 116.22.4880790.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 16919, with CSN 11060059388703 and transaction ID 30.0.14789262.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 17440, with CSN 11060059388705 and transaction ID 30.2.14788348.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 17961, with CSN 11060059388706 and transaction ID 28.13.2691889.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 18480, with CSN 11060059388707 and transaction ID 30.27.14798547.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 19002, with CSN 11060059388721 and transaction ID 46.20.22216904.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 19885, with CSN 11060059388787 and transaction ID 46.3.22228697.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 20291, with CSN 11060059388791 and transaction ID 116.0.4871324.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 20784, with CSN 11060059388793 and transaction ID 46.22.22217942.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 21199, with CSN 11060059388864 and transaction ID 43.16.18938572.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 25765, with CSN 11060059389426 and transaction ID 5.15.15270701.
2017-04-03 14:57:34  INFO    OGG-05652  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  CSN-based filtering suppressed a duplicate transaction from ./dirdat/R1WMP989/wm002971, RBA 91034, with CSN 11060059389846 and transaction ID 46.5.22230695.
2017-04-03 14:57:38  WARNING OGG-01498  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  Aborting BATCHSQL transaction. Database error 100 (retrieving bind info for query).
2017-04-03 14:57:38  WARNING OGG-01137  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  BATCHSQL suspended, continuing in normal mode.
2017-04-03 14:57:38  WARNING OGG-01003  Oracle GoldenGate Delivery for Oracle, R1WMP989.prm:  Repositioning to rba 10506557 in seqno 2971.

This command appeared in GG 11.2.1.0.7 and we are using 11.2.1.0.33

Advertisements

One Response to “GoldenGate – Restarting a replicat with the command filterduptransactions”

  1. If you are using an integrated replicat, GoldenGate filters duplicate transactions automatically and transparently.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

 
%d bloggers like this: