Re: Huge plain inserts response time bad with db file sequential read wait event.

Hi All,

Below are top wait events:

  1864  _at_2, GGS       , TIME, DB time
             ,       5717208,   951.49ms,    95.1%, [##########],
,           ,       3.28 % unaccounted time
  1864  _at_2, GGS       , WAIT, db file sequential read
             ,       5485206,   912.88ms,    91.3%, [WWWWWWWWWW],
 353,      58.75,    15.54ms

As per above db file sequenatial is top and again single wait is 15.54 ms which is way to high modern Storage systems.

Seems like you are running on some Test / Dev boxes. If it is prod, then check with storage team to check if underlying disk performance can be improved by removing any bottlenecks

On query side do the following:

- Drop the indexes before run
- Disable the triggers if possible
- Run it is multiple batches and have frequent commits

GC waits are under control as of now

Regards,
Harmandeep Singh

On Fri, Dec 21, 2018 at 2:01 AM Mark W. Farnham <mwf_at_rsiz.com> wrote:

> A starting point suggestion is to use a listener service for the
> connection of sessions that do this with a primary and secondary node so
> that all the sessions doing this insert perform this insert on the primary
> node except when it is down (in which case they all go to the secondary
> node).
>
>
>
> IF this wait is due to gcc two way traffic, most of the time will simply
> evaporate. It is probably cheaper and quicker to just try it than to dice
> out the metrics and proof in advance.
>
>
>
> good luck
>
>
>
> mwf
>
>
>
>
>
> *From:* oracle-l-bounce_at_freelists.org [mailto:
> oracle-l-bounce_at_freelists.org] *On Behalf Of *Rakesh Ra
> *Sent:* Thursday, December 20, 2018 12:49 PM
> *To:* oracle-l_at_freelists.org
> *Cc:* Rakesh RA
> *Subject:* Re: Huge plain inserts response time bad with db file
> sequential read wait event.
>
>
>
> Forgot to mention the database is of version 11.2.0.4 and a 2 node RAC
> system.
>
>
>
> Regards,
>
> RRA
>
>
>
> On Thu, Dec 20, 2018 at 11:18 PM Rakesh Ra <rakeshra.tr_at_gmail.com> wrote:
>
> Hi All,
>
>
>
> I have an issue where the below query response time is bad when there is
> huge number of concurrent executions.
>
>
>
> SQL_ID SQL_FULLTEXT
> PARSING_SCHEMA_NAME
>
> -------------
> --------------------------------------------------------------------------------
> ------------------------------
>
> g4cf65js6kjf0 INSERT /*+ RESTRICT_ALL_REF_CONS */ INTO
> "DR_CORE09"."ITEM_M GGS
>
> ETADATA_PROPERTY" ("ITEM_METADATA_PROPER
>
> TY_SID","CREATED_BY","CREATED_DATE","MOD
>
> IFIED_BY","MODIFIED_DATE","CHANGED","ITE
>
> M_EXTERNAL_ID","PROPERTY_NAME","PROPERTY
>
> _TYPE","BOOLEAN_VALUE","INT_VALUE","TIME
>
> STAMP_VALUE","CUSTOMER_STORAGE_ID","STRI
>
> NG_VALUE","APP_CREATED_DATE","APP_MODIFI
>
> ED_DATE","VARCHAR_VALUE","CLOB_VALUE","R
>
> ESOURCE_STATUS") VALUES (:a0,:a1,:a2,:a3
>
> ,:a4,:a5,:a6,:a7,:a8,:a9,:a10,:a11,:a12,
>
> :a13,:a14,:a15,:a16,:a17,:a18)
>
>
>
> When I check gv$ash and 10046 trace I see that the query is waiting on db
> file sequential read for PK index as below.
>
>
>
> EVENT SQL_ID CURRENT_OBJ# MODULE
> PCT
>
> ------------------------------------ ------------- ------------
> ------------------------------------
> ------------------------------------------------------------------------
>
> db file sequential read g4cf65js6kjf0 410319
> OGG-R1_825B-OPEN_DATA_SOURCE 33.5%<<<<<<<<<
>
> db file sequential read gabtdu60mta41 410432
> OGG-R1_825B-OPEN_DATA_SOURCE 3.6%
>
> db file sequential read g4cf65js6kjf0 699497
> OGG-R1_825B-OPEN_DATA_SOURCE 2.5%
>
> db file sequential read g4cf65js6kjf0 410320
> OGG-R1_825B-OPEN_DATA_SOURCE 2.3%
>
>
>
>
>
> Name Null? Type
>
> ------------------------------------- --------
> --------------------------------
>
> ITEM_METADATA_PROPERTY_SID NOT NULL VARCHAR2(32)
>
> CREATED_BY NOT NULL VARCHAR2(75 CHAR)
>
> CREATED_DATE NOT NULL TIMESTAMP(6)
>
> MODIFIED_BY NOT NULL VARCHAR2(75 CHAR)
>
> MODIFIED_DATE TIMESTAMP(6)
>
> CHANGED NOT NULL TIMESTAMP(6)
>
> ITEM_EXTERNAL_ID NOT NULL VARCHAR2(36 CHAR)
>
> PROPERTY_NAME NOT NULL VARCHAR2(500 CHAR)
>
> PROPERTY_TYPE NOT NULL NUMBER
>
> BOOLEAN_VALUE NUMBER(1)
>
> INT_VALUE NUMBER
>
> TIMESTAMP_VALUE TIMESTAMP(6)
>
> CUSTOMER_STORAGE_ID NOT NULL VARCHAR2(32)
>
> STRING_VALUE CLOB
>
> APP_CREATED_DATE TIMESTAMP(6)
>
> APP_MODIFIED_DATE TIMESTAMP(6)
>
> VARCHAR_VALUE VARCHAR2(1000 CHAR)
>
> CLOB_VALUE CLOB
>
> RESOURCE_STATUS NOT NULL VARCHAR2(3 CHAR)
>
>
>
> OWNER OBJECT_ID OBJECT_NAME
>
> ------------------ ---------- ---------------------------
>
> DR_CORE09 410319 ITEM_METADATA_PROPERTY_PK<<<<<<<<<<<<
>
>
>
> Please note that this query is being executed by the Oracle GoldenGate
> replicat process.
>
>
>
> I have attached snapper details and below is the execution plan. Also I am
> not sure why the CPU costing is off for the plan. This is observed only for
> OGG queries. Other application related JDBC queries I see all the plan
> table related columns.
>
>
>
> PLAN_TABLE_OUTPUT
>
>
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> SQL_ID g4cf65js6kjf0, child number 0
>
> -------------------------------------
>
> INSERT /*+ RESTRICT_ALL_REF_CONS */ INTO
>
> "DR_CORE09"."ITEM_METADATA_PROPERTY"
>
> ("ITEM_METADATA_PROPERTY_SID","CREATED_BY","CREATED_DATE","MODIFIED_BY",
>
> "MODIFIED_DATE","CHANGED","ITEM_EXTERNAL_ID","PROPERTY_NAME","PROPERTY_T
>
> YPE","BOOLEAN_VALUE","INT_VALUE","TIMESTAMP_VALUE","CUSTOMER_STORAGE_ID"
>
> ,"STRING_VALUE","APP_CREATED_DATE","APP_MODIFIED_DATE","VARCHAR_VALUE","
>
> CLOB_VALUE","RESOURCE_STATUS") VALUES
>
> (:a0,:a1,:a2,:a3,:a4,:a5,:a6,:a7,:a8,:a9,:a10,:a11,:a12,:a13,:a14,:a15,:
>
> a16,:a17,:a18)
>
>
>
> -----------------------------------------------
>
> | Id | Operation | Name | Cost |
>
> -------------------------------------------------
>
> | 0 | INSERT STATEMENT | | 1 |
>
> | 1 | LOAD TABLE CONVENTIONAL | | |
>
> -------------------------------------------------
>
>
>
> Note
>
> -----
>
> - cpu costing is off (consider enabling it)
>
>
>
> Can someone guide as to,
>
>
>
> a) Why INSERT is spending more time on db file sequential reads for PK
> index?
>
> b) Why CPU costing is showing as off in the execution plan for OGG queries
> only?
>
>
>
> Regards,
>
> RRA
>
>

--
http://www.freelists.org/webpage/oracle-l