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

From: Rakesh Ra <rakeshra.tr_at_gmail.com>
Date: Thu, 20 Dec 2018 23:18:57 +0530
Message-ID: <CAOGpvWqevqJPpTUuh79L9iJiQjc=_tFRP6fwJYfd8oP3fP48Ww_at_mail.gmail.com>



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
Received on Thu Dec 20 2018 - 18:48:57 CET

Original text of this message