From the snapper output you're db file sequential read times are in the order
of 16ms which is clearly a bit slow (I'd expect to see something between 1 and
2 ms) - suggesting that the disks are overloaded. It's not just the PK index,
of course - your first set of stats show that you've got at least 2 other
indexes on the objects which are affected. When you insert data into a table
the number of index leaf blocks you have to update is usually larger (sometime
much larger) than the number of table blocks and you often have to find and
read the right index leaf block to insert into it whereas inserting "the next
row" into a table simply means adding one more row to a block that you've been
using in the last few milliseconds. Why the PK index should require more reads
than any other index - could simply be related to the definition of the index;
perhaps the other two indexes you report are very small (lots of nulls), or are
based on columns which are well-ordered relative to the inserts so need only
suffer a single read for every couple of dozen inserts.
Apart for the indications of "slow read time" however, there are various clues
about CPU overload. As Mark Farnham points out you are doing a lot of work
negotiating current grants to data blocks - and some of the blocks you are
interested in are busy: the negotiations can burn up CPU. We can also see a
lot of waits for library cache locks and pins - you really shouldn't be seeing
many of those waits at all - and that's another clue that there's a lot of CPU
disappearing (not necessarily in your session) in an over active library cache.
Inference - not only might your disks be overloaded, you may be suffering from
CPU starvation, which would exaggerate all wait times because "wait" time can
include time spent in the CPU queue but unable to use the CPU.
The note about "cpu costing is off" could simply be a bug - I've just run a
quick test on 11.2.0.4 for "insert (values)" for a table with object stats, an
up to date plan_table, system stats set, and I've just got the same note on the
plan. It doesn't matter for "insert (values)" because there is no plan to be
costed anyway, and Oracle wouldn't give you a clue about the cost of
maintaining all the indexes anyway.
Regards
Jonathan Lewis
________________________________________
From: oracle-l-bounce@xxxxxxxxxxxxx <oracle-l-bounce@xxxxxxxxxxxxx> on behalf
of Rakesh Ra <rakeshra.tr@xxxxxxxxx>
Sent: 20 December 2018 17:48
To: oracle-l@xxxxxxxxxxxxx
Subject: Huge plain inserts response time bad with db file sequential read wait
event.
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%
--
//www.freelists.org/webpage/oracle-l
