9 Replies Latest reply on Aug 13, 2019 5:53 AM by Robeen

    extract lag increasing

    Robeen

      Oracle Database 12.1.0.2 RAC

       

      Hello,

       

      I noticed the lag continues to increase

       

      Program     Status      Group       Lag at Chkpt  Time Since Chkpt

       

      MANAGER     RUNNING

      EXTRACT     RUNNING     EXTDWH      01:07:29      00:00:05

      EXTRACT     ABENDED     PXDWN       00:00:00      01:08:37

       

       

      GGSCI (proddb1) 3> VIEW REPORT EXTDWH

       

       

       

       

      ***********************************************************************

                       Oracle GoldenGate Capture for Oracle

          Version 18.1.0.0.0 OGGCORE_18.1.0.0.0_PLATFORMS_180928.0432_FBO

      Solaris, sparc, 64bit (optimized), Oracle 12c on Sep 30 2018 10:11:14

       

       

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

       

       

                          Starting at 2019-08-12 15:27:16

      ***********************************************************************

       

       

      Operating System Version:

      SunOS

      Version 11.4.9.5.0, Release 5.11

      Node: proddb1

      Machine: sun4v

                               soft limit   hard limit

      Address Space Size   :    unlimited    unlimited

      Heap Size            :    unlimited    unlimited

      File Size            :    unlimited    unlimited

      CPU Time             :    unlimited    unlimited

       

       

      Process id: 1679

       

       

      Description:

       

       

      ***********************************************************************

      **            Running with the following parameters                  **

      ***********************************************************************

       

       

      2019-08-12 15:27:16  INFO    OGG-03059  Operating system character set identified as US-ASCII.

       

       

      2019-08-12 15:27:16  INFO    OGG-02695  ANSI SQL parameter syntax is used for parameter parsing.

       

       

      2019-08-12 15:27:16  INFO    OGG-01360  EXTRACT is running in Integrated mode.

      EXTRACT EXTDWH

      USERIDALIAS oggscb_dwh

      DDL INCLUDE MAPPED

      DDLOPTIONS REPORT

      TRANLOGOPTIONS MININGUSERALIAS oraggext

      TRANLOGOPTIONS INTEGRATEDPARAMS (downstream_real_time_mine Y)

      TRANLOGOPTIONS INCLUDEREGIONID

      EXTTRAIL /ogg/ora12c/dirdat/aa

      TABLE CBS_CORE.CB_INSTALLMENT;

      TABLE CBS_CORE.CB_INSTALLMENT_DTLS;

      TABLE CBS_CORE.cb_serv_installment_dtls;

      TABLE CBS_CORE.cb_subs_deposits;

      TABLE CBS_CORE.cb_bill_cycle;

      TABLE CBS_CORE.cb_order_request_dtls;

      TABLE CBS_CORE.CB_WORK_ORDER;

      TABLE CBS_CORE.WF_WRKFLWMGR;

      TABLE CBS_CORE.CB_SUBS_PROVISIONING;

      TABLE CBS_CORE.CB_POS_SERVICES;

      TABLE CBS_CORE.CB_WORK_ORDER_PRODUCT_DTLS;

      TABLE CBS_CORE.INV_ITEM_MASTER;

      TABLE  CBS_CORE.CB_SUB_AR_AP;

      TABLE CLM_TT.WF_WORKASSIGNMENT_HISTORY;

      TABLE CLM_TT.CB_FAULT_TYPES;

      TABLE CLM_TT.TT_TICKET_ADDNL_INFO;

      TABLE  CLM_TT.TT_TICKETINFO;

      TABLE CLM_TT.WF_WORKASSIGNMENT;

      TABLE CLM_TT.WF_TODOITEM;

      TABLE CBS_CORE.WF_USERGROUP;

      TABLE CLM_TT.WF_TODOITEM_HISTORY;

      TABLE CLM_TT.TT_TICKETINCIDENT;

      TABLE CBS_CORE.CB_USER_GROUP;

      TABLE CLM_TT.TT_CATEGORY_MASTER;

      TABLE CLM_TT.WF_WORKFLOW;

      TABLE CBS_CORE.cb_offers;

      TABLE CBS_CORE.CB_USERS;

      TABLE CBS_CORE.CB_SUB_SERVICES;

      TABLE  CBS_CORE.CB_SUB_INVOICE;

      TABLE  CBS_CORE.CB_BANK_MASTER;

      TABLE  CBS_CORE.CB_CR_DB_NOTES;

      TABLE CBS_CORE.CB_REASON_MASTER;

      TABLE CBS_CORE.CB_POS_SERVICES_PARAMS;

      TABLE  CBS_CORE.CB_SUBS_OFFER_DETAILS;

      TABLE CBS_CORE.CB_SUBS_PAID_ADV_DTLS;

      TABLE  CBS_CORE.CB_SUBSCRIBER_SUB_CATEGORY;

      TABLE  CBS_CORE.CB_SUBSCRIBER_MASTER;

      TABLE  CBS_CORE.CB_SUBS_POS_SERVICES;

      TABLE  CBS_CORE.CB_SUBSCRIBER_CATEGORY;

      TABLE  CBS_CORE.CB_ADDRESS_XML;

      TABLE  CBS_CORE.CB_RETAIL_OUTLETS;

      TABLE  CBS_CORE.CB_RECEIPTS;

      TABLE  CBS_CUST.CB_POS_TRANS_DTLS;

      TABLE CBS_CUST.CB_POS_TRANSACTIONS;

      TABLE  CBS_CORE.CB_RECEIPTS_ADJUST;

      TABLE  CBS_CORE.fxl_cycle_summary_details;

      TABLE CBS_CORE.CB_ADVANCE_RENTAL;

      TABLE  CBS_CORE.CB_PACKAGE;

      TABLE  CBS_CORE.CB_OFFERS;

      TABLE  CBS_CORE.CB_INVOICE_DETAILS;

      TABLE  CBS_CORE.CB_INVOICE;

      TABLE  CBS_CORE.CB_DEALER_MASTER;

      TABLE  CBS_CORE.CB_ARTICLE_GROUPS;

      TABLE  CBS_CORE.CB_ARTICLES;

      TABLE  CBS_CORE.PS_ACTION;

      TABLE  CBS_CORE.CB_ACCOUNT_SERVICE_LIST;

      TABLE  CBS_CORE.CB_ACCOUNT_RECEIVE_PAY;

      TABLE  CBS_CORE.CB_ACCOUNT_MASTER;

      TABLE  CBS_CORE.CB_STATUS_MASTER;

      TABLE  CBS_CORE.CB_SERVICES;

      TABLE  CBS_CORE.CB_ACCS_RECEIVE_PAY_ADJUST;

      TABLE  CBS_CORE.CB_SUBS_REFUND;

      TABLE  CBS_CORE.GSM_SERVICE_MAST;

      TABLE  CBS_CORE.CB_PAY_MODE_DTLS;

      TABLE  CBS_CORE.CB_PAYMENT_METHODS;

      TABLE  CBS_CORE.CB_SCHEME_REFERENCE;

      TABLE  CBS_CORE.CB_CANCEL_RECEIPTS;

      TABLE  CBS_CORE.FXL_SERVICE_MAST;

       

       

      2019-08-12 15:27:21  INFO    OGG-01635  BOUNDED RECOVERY: reset to initial or altered checkpoint.

       

       

      2019-08-12 15:27:21  INFO    OGG-01815  Virtual Memory Facilities for: BR

          anon alloc: mmap(MAP_ANON)  anon free: munmap

          file alloc: mmap(MAP_SHARED)  file free: munmap

          target directories:

          /ogg/ora12c/BR/EXTDWH.

       

       

      Bounded Recovery Parameter:

      BRINTERVAL = 4HOURS

      BRDIR      = /ogg/ora12c/

       

       

      2019-08-12 15:27:21  INFO    OGG-01851  filecaching started: thread ID: 6.

       

       

      2019-08-12 15:27:21  INFO    OGG-01815  Virtual Memory Facilities for: COM

          anon alloc: mmap(MAP_ANON)  anon free: munmap

          file alloc: mmap(MAP_SHARED)  file free: munmap

          target directories:

          /ogg/ora12c/dirtmp.

       

       

      2019-08-12 15:28:03  WARNING OGG-01842  CACHESIZE PER DYNAMIC DETERMINATION (62.19G) LESS THAN RECOMMENDED: 64G (64bit system)

      vm found: 70.19G

      Check swap space. Recommended swap/extract: 128G (64bit system).

       

       

      Database Version:

      Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production

      PL/SQL Release 12.1.0.2.0 - Production

      CORE    12.1.0.2.0      Production

      TNS for Solaris: Version 12.1.0.2.0 - Production

      NLSRTL Version 12.1.0.2.0 - Production

       

       

      Database Language and Character Set:

      NLS_LANGUAGE     = "AMERICAN"

      NLS_TERRITORY    = "AMERICA"

      NLS_CHARACTERSET = "WE8MSWIN1252"

       

       

      2019-08-12 15:28:05  INFO    OGG-06604  Database CBS CPU info: CPU Count 80, CPU Core Count 10, CPU Socket Count 1.

       

       

      2019-08-12 15:28:05  INFO    OGG-06604  Database GGCBS CPU info: CPU Count 16, CPU Core Count 2, CPU Socket Count 1.

       

       

      2019-08-12 15:28:09  WARNING OGG-02045  Database does not have streams_pool_size initialization parameter configured.

       

       

      2019-08-12 15:28:09  INFO    OGG-02248  Logmining server DDL filtering enabled.

       

       

      2019-08-12 15:28:10  INFO    OGG-02068  Integrated capture successfully attached to logmining server OGG$CAP_EXTDWH using OGGCapture API.

       

       

      2019-08-12 15:28:10  INFO    OGG-02089  Source redo compatibility version is: 12.1.0.2.0.

       

       

      2019-08-12 15:28:10  INFO    OGG-02086  Integrated Dictionary will be used.

       

       

      2019-08-12 15:28:10  WARNING OGG-02905  Replication of OID column in object tables may diverge.

       

       

      2019-08-12 15:28:10  INFO    OGG-01052  No recovery is required for target file /ogg/ora12c/dirdat/aa000000000, at RBA 0 (file not opened).

       

       

      2019-08-12 15:28:10  INFO    OGG-01478  Output file /ogg/ora12c/dirdat/aa is using format RELEASE 12.3/18.1.

       

       

      ***********************************************************************

      **                     Run Time Messages                             **

      ***********************************************************************

       

       

       

       

      2019-08-12 15:44:56  INFO    OGG-01021  Command received from GGSCI: STATUS.

       

       

      2019-08-12 15:45:26  INFO    OGG-01971  The previous message, 'INFO OGG-01021', repeated 1 times.

       

       

      2019-08-12 16:24:15  INFO    OGG-01971  The previous message, 'INFO OGG-01021', repeated 1 times.

       

       

      2019-08-12 16:24:15  INFO    OGG-01021  Command received from GGSCI: REPORT.

       

       

      ***********************************************************************

      *                   ** Run Time Statistics **                         *

      ***********************************************************************

       

       

       

       

      Report at 2019-08-12 16:24:15 (activity since 2019-08-12 15:27:16)

       

       

      Output to /ogg/ora12c/dirdat/aa:

       

       

       

       

       

       

      DDL replication statistics:

       

       

                          Operations:         0

                   Mapped operations:         0

                 Unmapped operations:         0

                    Other operations:         0

                 Excluded operations:         0

       

       

       

       

      No records extracted.

       

       

       

       

      ***********************************************************************

      **                     Run Time Warnings                             **

      ***********************************************************************

       

      Please help.

       

      Regards,

       

      Joe

        • 1. Re: extract lag increasing
          ORASCN

          Hi Joe,

           

          Check if the Extract is really capturing the data?

           

          stats extract <ext_name>

           

          Regards,

          Veera

          • 2. Re: extract lag increasing
            Robeen

            Hi Veera,

             

            GGSCI (proddb1) 3> stats extract EXTDWH

             

             

            Sending STATS request to EXTRACT EXTDWH ...

             

             

            No active extraction maps.

            DDL replication statistics (for all trails):

             

             

            *** Total statistics since extract started     ***

                    Operations                                         0.00

                    Mapped operations                                  0.00

                    Unmapped operations                                0.00

                    Other operations                                   0.00

                    Excluded operations                                0.00

             

            Regards,

             

            Joe

            • 3. Re: extract lag increasing
              ORASCN

              Hi Joe,

               

              Please share the below,

               

              info extract <ext_name>, detail

               

              Check the alert log file, if the Extract (capture) is really mining the redo logs and capturing the data.

               

              Regards,

              Veera

              • 4. Re: extract lag increasing
                Robeen

                Hi Veera,

                 

                GGSCI (proddb1) 1> info extract EXTDWH detail

                 

                 

                EXTRACT    EXTDWH    Last Started 2019-08-12 17:03   Status RUNNING

                Checkpoint Lag       00:00:03 (updated 00:00:06 ago)

                Process ID           16541

                Log Read Checkpoint  Oracle Integrated Redo Logs

                                     2019-08-12 17:06:04

                                     SCN 0.46459364 (46459364)

                 

                 

                  Target Extract Trails:

                 

                 

                  Trail Name                                       Seqno        RBA     Max MB Trail Type

                 

                 

                  /ogg/ora12c/dirdat/aa                                2       1409        500 EXTTRAIL

                 

                GGSCI (proddb1) 2> info extract EXTDWH detail

                 

                 

                EXTRACT    EXTDWH    Last Started 2019-08-12 17:03   Status RUNNING

                Checkpoint Lag       00:00:03 (updated 00:00:01 ago)

                Process ID           16541

                Log Read Checkpoint  Oracle Integrated Redo Logs

                                     2019-08-12 17:06:55

                                     SCN 0.46460086 (46460086)

                 

                 

                  Target Extract Trails:

                 

                 

                  Trail Name                                       Seqno        RBA     Max MB Trail Type

                 

                 

                  /ogg/ora12c/dirdat/aa                                2       1409        500 EXTTRAIL

                 

                GGSCI (proddb1) 3> info extract EXTDWH detail

                 

                 

                EXTRACT    EXTDWH    Last Started 2019-08-12 17:03   Status RUNNING

                Checkpoint Lag       00:00:04 (updated 00:00:08 ago)

                Process ID           16541

                Log Read Checkpoint  Oracle Integrated Redo Logs

                                     2019-08-12 17:07:14

                                     SCN 0.46460521 (46460521)

                 

                 

                  Target Extract Trails:

                 

                 

                  Trail Name                                       Seqno        RBA     Max MB Trail Type

                 

                 

                  /ogg/ora12c/dirdat/aa                                2       1409        500 EXTTRAIL

                 

                GGSCI (proddb1) 4> info EXTDWH showch

                 

                 

                EXTRACT    EXTDWH    Last Started 2019-08-12 17:03   Status RUNNING

                Checkpoint Lag       00:00:04 (updated 00:00:04 ago)

                Process ID           16541

                Log Read Checkpoint  Oracle Integrated Redo Logs

                                     2019-08-12 17:07:34

                                     SCN 0.46460873 (46460873)

                 

                 

                 

                 

                Current Checkpoint Detail:

                 

                 

                Read Checkpoint #1

                 

                 

                  Oracle Integrated Redo Log

                 

                 

                  Startup Checkpoint (starting position in the data source):

                    Timestamp: 2019-08-12 15:19:14.000000

                    SCN: Not available

                 

                 

                  Recovery Checkpoint (position of oldest unprocessed transaction in the data source):

                    Timestamp: 2019-08-12 17:07:34.000000

                    SCN: 0.46460872 (46460872)

                 

                 

                  Current Checkpoint (position of last record read in the data source):

                    Timestamp: 2019-08-12 17:07:34.000000

                    SCN: 0.46460873 (46460873)

                 

                 

                Write Checkpoint #1

                 

                 

                  GGS Log Trail

                 

                 

                  Current Checkpoint (current write position):

                    Sequence #: 2

                    RBA: 1409

                    Timestamp: 2019-08-12 17:07:38.220738

                    Extract Trail: /ogg/ora12c/dirdat/aa

                    Seqno Length: 9

                    Flip Seqno Length: No

                    Trail Type: EXTTRAIL

                 

                 

                Header:

                  Version = 2

                  Record Source = A

                  Type = 13

                  # Input Checkpoints = 1

                  # Output Checkpoints = 1

                 

                 

                File Information:

                  Block Size = 2048

                  Max Blocks = 100

                  Record Length = 2048

                  Current Offset = 0

                 

                 

                Configuration:

                  Data Source = 3

                  Transaction Integrity = 1

                  Task Type = 0

                 

                 

                Status:

                  Start Time = 2019-08-12 17:03:37

                  Last Update Time = 2019-08-12 17:07:38

                  Stop Status = A

                  Last Result = 520

                 

                 

                 

                 

                 

                 

                GGSCI (proddb1) 5> info EXTDWH showch

                 

                 

                EXTRACT    EXTDWH    Last Started 2019-08-12 17:03   Status RUNNING

                Checkpoint Lag       00:00:03 (updated 00:00:04 ago)

                Process ID           16541

                Log Read Checkpoint  Oracle Integrated Redo Logs

                                     2019-08-12 17:07:45

                                     SCN 0.46461013 (46461013)

                 

                 

                 

                 

                Current Checkpoint Detail:

                 

                 

                Read Checkpoint #1

                 

                 

                  Oracle Integrated Redo Log

                 

                 

                  Startup Checkpoint (starting position in the data source):

                    Timestamp: 2019-08-12 15:19:14.000000

                    SCN: Not available

                 

                 

                  Recovery Checkpoint (position of oldest unprocessed transaction in the data source):

                    Timestamp: 2019-08-12 17:07:45.000000

                    SCN: 0.46461013 (46461013)

                 

                 

                  Current Checkpoint (position of last record read in the data source):

                    Timestamp: 2019-08-12 17:07:45.000000

                    SCN: 0.46461013 (46461013)

                 

                 

                Write Checkpoint #1

                 

                 

                  GGS Log Trail

                 

                 

                  Current Checkpoint (current write position):

                    Sequence #: 2

                    RBA: 1409

                    Timestamp: 2019-08-12 17:07:48.223384

                    Extract Trail: /ogg/ora12c/dirdat/aa

                    Seqno Length: 9

                    Flip Seqno Length: No

                    Trail Type: EXTTRAIL

                 

                 

                Header:

                  Version = 2

                  Record Source = A

                  Type = 13

                  # Input Checkpoints = 1

                  # Output Checkpoints = 1

                 

                 

                File Information:

                  Block Size = 2048

                  Max Blocks = 100

                  Record Length = 2048

                  Current Offset = 0

                 

                 

                Configuration:

                  Data Source = 3

                  Transaction Integrity = 1

                  Task Type = 0

                 

                 

                Status:

                  Start Time = 2019-08-12 17:03:37

                  Last Update Time = 2019-08-12 17:07:48

                  Stop Status = A

                  Last Result = 520

                 

                 

                 

                 

                 

                 

                GGSCI (proddb1) 6>

                 

                When I first started the extract, ialert log was showing the mining processes.

                 

                Regards,

                 

                Joe

                • 5. Re: extract lag increasing
                  ORASCN

                  Hi Joe,

                   

                  The starting checkpoint of the Extract is showing as "Not Available".

                   

                  Could you please execute the below command for couple of times or thrice and share the output,

                   

                  send extract <ext_name>, status

                   

                  Regards,

                  Veera

                  • 6. Re: extract lag increasing
                    Robeen

                    Hi Veera,

                     

                    I restarted the extract and it seems ok now

                     

                    GGSCI (proddb1) 2> send extract EXTDWH status

                     

                     

                    Sending STATUS request to EXTRACT EXTDWH ...

                    EXTRACT EXTDWH (PID 26925)

                      Current status: Recovery complete: Processing data

                     

                     

                      Current read position:

                      Redo thread #: 2

                      Sequence #: 129

                      RBA: 2013024

                      Timestamp: 2019-08-12 19:16:42.000000

                      SCN: 0.46633973 (46633973)

                      Current write position:

                      Sequence #: 4

                      RBA: 3206

                      Timestamp: 2019-08-12 19:16:36.344741

                      Extract Trail: /ogg/ora12c/dirdat/aa

                     

                    GGSCI (proddb1) 3> send extract EXTDWH status

                     

                     

                    Sending STATUS request to EXTRACT EXTDWH ...

                    EXTRACT EXTDWH (PID 26925)

                      Current status: Recovery complete: Processing data

                     

                     

                      Current read position:

                      Redo thread #: 2

                      Sequence #: 129

                      RBA: 2261300

                      Timestamp: 2019-08-12 19:17:13.000000

                      SCN: 0.46634545 (46634545)

                      Current write position:

                      Sequence #: 4

                      RBA: 3206

                      Timestamp: 2019-08-12 19:17:06.360362

                      Extract Trail: /ogg/ora12c/dirdat/aa

                     

                    GGSCI (proddb1) 4> send extract EXTDWH status

                     

                     

                    Sending STATUS request to EXTRACT EXTDWH ...

                    EXTRACT EXTDWH (PID 26925)

                      Current status: Recovery complete: Processing data

                     

                     

                      Current read position:

                      Redo thread #: 2

                      Sequence #: 129

                      RBA: 2468176

                      Timestamp: 2019-08-12 19:17:30.000000

                      SCN: 0.46634818 (46634818)

                      Current write position:

                      Sequence #: 4

                      RBA: 3206

                      Timestamp: 2019-08-12 19:17:26.370926

                      Extract Trail: /ogg/ora12c/dirdat/aa

                     

                    Is it normal if it is in 'processing data'? If the SCN is changing, does it mean the extract is progressing?

                     

                    Regards,

                     

                    Joe

                    • 7. Re: extract lag increasing
                      K.Gan

                      Hi Joe

                      This is an on again off again bug with Oracle that they don't seem to be able to nail. When an extract or replicat for that matter never encounters a transaction it wants, it never checkpoints. Use to be worst, running extracts that have encountered transactions but have not seen another for a length of time also did not checkpoint.

                      Cheers

                      Kee Gan

                      1 person found this helpful
                      • 8. Re: extract lag increasing
                        ORASCN

                        Hi Joe,

                         

                        Yes, it is normal.

                         

                        For example, if you are having employee table in the Extract process and if there are no operations for that particular table in the database, you will see the message "No Active Extraction Maps". This is a general message.

                         

                        To check if the extract process is processing correctly, simply create a table and add it to the extract parameter file. Do an Insert and execute the STATS command. You should see that INSERT in the STATS command output.

                         

                        Regards,

                        Veera

                        1 person found this helpful
                        • 9. Re: extract lag increasing
                          Robeen

                          Hi,

                           

                          yes, I created a table on source and added in extract and replicat.

                           

                          It is ok now.

                           

                          Thanks loads for your advise.

                           

                          Regards,

                           

                          Joe