Monday, 27 November 2017

ERROR OGG-00446 Unable to lock file while starting Goldengate extract

The Golden gate is installed on a 2-node RAC cluster and registered with Oracle clusterware through Bundle Agent.


On starting the goldengate gg_1 on 1st node, the Goldengate logfile ggserr.log shows following error:

2017-11-27 09:00:22  INFO    OGG-01971  Oracle GoldenGate Capture for Oracle, ggpump.prm:  The previous message, 'INFO OGG-02095', repeated 1 times.
2017-11-27 09:00:22  INFO    OGG-03522  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Setting session time zone to source database time zone 'GMT'.
2017-11-27 09:00:22  INFO    OGG-01971  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  The previous message, 'INFO OGG-02095', repeated 1 times.
2017-11-27 09:00:22  INFO    OGG-03522  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Setting session time zone to source database time zone 'GMT'.
2017-11-27 09:00:27  INFO    OGG-00987  Oracle GoldenGate Command Interpreter for Oracle:  GGSCI command (oracle): info mgr.
2017-11-27 09:00:32  ERROR   OGG-00446  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Unable to lock file "/u01/app/oracle/product/12.1.2/oggcore_1/dirchk/GGPUMP.cpe" (error 11, Resource temporarily unavailable).
2017-11-27 09:00:32  ERROR   OGG-00446  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Unable to lock file "/u01/app/oracle/product/12.1.2/oggcore_1/dirchk/ORA12C16.cpe" (error 11, Resource temporarily unavailable).
2017-11-27 09:00:32  ERROR   OGG-01668  Oracle GoldenGate Capture for Oracle, ggpump.prm:  PROCESS ABENDING.
2017-11-27 09:00:33  ERROR   OGG-01668  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  PROCESS ABENDING.

Extract process is not able to obtain lock on the below files:

[oracle@lon2odclborc001a oggcore_1]$ pwd
/u01/app/oracle/product/12.1.2/oggcore_1
[oracle@lon2odclborc001a oggcore_1]$ ls -l dirchk/
total 196
-rw-r----- 1 oracle oinstall  32768 Nov 27 09:17 GGPUMP.cpe
-rw-r----- 1 oracle oinstall   6144 Nov 27 06:47 ORA12C16.cpb
-rw-r----- 1 oracle oinstall 122880 Nov 27 09:17 ORA12C16.cpe

Clusterware shows that Goldengate is running only on node rac01a:

[oracle@rac01a ~]$ agctl status goldengate gg_1
Goldengate  instance 'gg_1' is running on rac01a

In RAC environment, the Goldengate manager process should run only on one node at a time.
But somehow, the manager and extract processes is also got started on the 2nd node.

On second node rac01b, 

[oracle@rac01b oggcore_1]$ cd /u01/app/oracle/product/12.1.2/oggcore_1
[oracle@rac01b oggcore_1]$ ./ggsci

Oracle GoldenGate Command Interpreter for Oracle
Version 12.2.0.1.1 OGGCORE_12.2.0.1.0_PLATFORMS_151211.1401_FBO
Linux, x64, 64bit (optimized), Oracle 12c on Dec 12 2015 02:56:48
Operating system character set identified as UTF-8.

Copyright (C) 1995, 2015, Oracle and/or its affiliates. All rights reserved.


GGSCI (rac01b.markit.partners) 1> status mgr

Manager is running (IP port rac01b.markit.partners.7809, Process ID 14153).

GGSCI (rac01b.markit.partners) 2> stop mgr
Manager process is required by other GGS processes.
Are you sure you want to stop it (y/n)?y

Sending STOP request to MANAGER ...
Request processed.
Manager stopped.

GGSCI (rac01b.markit.partners) 4> stop ER *

Sending STOP request to EXTRACT GGPUMP ...
Request processed.

Sending STOP request to EXTRACT ORA12C16 ...
Request processed.


GGSCI (rac01b.markit.partners) 5> info all

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     STOPPED
EXTRACT     STOPPED     GGPUMP      00:00:00      00:05:23
EXTRACT     STOPPED     ORA12C16    00:00:00      00:05:22



Restart the GoldenGate

[oracle@rac01a ~]$ agctl stop goldengate gg_1
[oracle@rac01a ~]$ agctl start goldengate gg_1
[oracle@rac01a ~]$ agctl status goldengate gg_1
Goldengate  instance 'gg_1' is running on rac01a

Check the GoldenGate extract and manager process

[oracle@rac01a oggcore_1]$ ./ggsci

Oracle GoldenGate Command Interpreter for Oracle
Version 12.2.0.1.1 OGGCORE_12.2.0.1.0_PLATFORMS_151211.1401_FBO
Linux, x64, 64bit (optimized), Oracle 12c on Dec 12 2015 02:56:48
Operating system character set identified as UTF-8.

Copyright (C) 1995, 2015, Oracle and/or its affiliates. All rights reserved.



GGSCI (rac01a.markit.partners) 1> info all

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING
EXTRACT     RUNNING     GGPUMP      00:00:00      00:00:04
EXTRACT     RUNNING     ORA12C16    00:00:00      00:00:04


Logfile shows no error stating that lock is released from 2nd node and extract process got started successfully.

[oracle@lon2odclborc001a oggcore_1]$ tail -100f ggserr.log
2017-11-27 09:32:25  INFO    OGG-02089  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Source redo compatibility version is: 12.1.0.
2017-11-27 09:32:25  INFO    OGG-00546  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Default thread stack size: 2097152.
2017-11-27 09:32:25  INFO    OGG-01513  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Positioning to (Thread 1) Sequence 3862, RBA 54800, SCN 0.8878361 (8878361).
2017-11-27 09:32:25  INFO    OGG-01516  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Positioned to (Thread 1) Sequence 3862, RBA 54800, SCN 0.8878361 (8878361), 27 Nov 2017 09:23:08.
2017-11-27 09:32:25  INFO    OGG-01513  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Positioning to (Thread 2) Sequence 3850, RBA 845328, SCN 0.8878352 (8878352).
2017-11-27 09:32:25  INFO    OGG-01516  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Positioned to (Thread 2) Sequence 3850, RBA 845328, SCN 0.8878352 (8878352), 27 Nov 2017 09:23:07.
2017-11-27 09:32:25  INFO    OGG-01517  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Position of first record processed for Thread 1, Sequence 3862, RBA 54800, SCN 0.8878361 (8878361), 27 Nov 2017 09:23:08.
2017-11-27 09:32:25  INFO    OGG-00993  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  EXTRACT ORA12C16 started.
2017-11-27 09:32:25  INFO    OGG-01517  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Position of first record processed for Thread 2, Sequence 3850, RBA 845328, SCN 0.8878352 (8878352), 27 Nov 2017 09:23:07.
2017-11-27 09:32:25  INFO    OGG-01055  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Recovery initialization completed for target file ./dirdat/aa000000012, at RBA 1535.
2017-11-27 09:32:25  INFO    OGG-01478  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Output file ./dirdat/aa is using format RELEASE 12.2.
2017-11-27 09:32:25  INFO    OGG-01026  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Rolling over remote file ./dirdat/aa000000012.
2017-11-27 09:32:25  INFO    OGG-01053  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Recovery completed for target file ./dirdat/aa000000013, at RBA 1535.
2017-11-27 09:32:25  INFO    OGG-01057  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Recovery completed for all targets.
2017-11-27 09:32:27  INFO    OGG-06507  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  MAP (TABLE) resolved (entry OGG_USER.GGS_MARKER): TABLE "OGG_USER"."GGS_MARKER".
2017-11-27 09:32:28  INFO    OGG-06509  Oracle GoldenGate Capture for Oracle, ora12c16.prm:  Using the following key columns for source table OGG_USER.GGS_MARKER: SEQNO, FRAGMENTNO, OPTIME.
2017-11-27 09:32:29  INFO    OGG-01226  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Socket buffer size set to 27985 (flush size 27985).
2017-11-27 09:32:29  INFO    OGG-01055  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Recovery initialization completed for target file ./dirdat/bb000000025, at RBA 1629.
2017-11-27 09:32:29  INFO    OGG-01478  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Output file ./dirdat/bb is using format RELEASE 12.2.
2017-11-27 09:32:30  INFO    OGG-01026  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Rolling over remote file ./dirdat/bb000000026.
2017-11-27 09:32:31  INFO    OGG-01053  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Recovery completed for target file ./dirdat/bb000000026, at RBA 850.
2017-11-27 09:32:31  INFO    OGG-01057  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Recovery completed for all targets.
2017-11-27 09:32:31  INFO    OGG-02243  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Opened trail file ./dirdat/aa000000012 at 2017-11-27 09:32:31.298588.
2017-11-27 09:32:31  INFO    OGG-02232  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Switching to next trail file ./dirdat/aa000000013 at 2017-11-27 09:32:31.298588 due to EOF. with current RBA 1,535.
2017-11-27 09:32:31  INFO    OGG-01026  Oracle GoldenGate Capture for Oracle, ggpump.prm:  Rolling over remote file ./dirdat/bb000000027.
2017-11-27 09:34:06  INFO    OGG-00987  Oracle GoldenGate Command Interpreter for Oracle:  GGSCI command (oracle): info all.

No comments:

Post a Comment