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
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SID @INST, USERNAME , TYPE, STATISTIC
, DELTA, HDELTA/SEC, %TIME, GRAPH , NUM_WAITS,
WAITS/SEC, AVERAGES
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
1864 @2, GGS , STAT, Requests to/from client
, 347, 53.68, , , ,
, .69 per execution
1864 @2, GGS , STAT, opened cursors cumulative
, 170, 26.3, , , ,
, .34 per execution
1864 @2, GGS , STAT, user commits
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, user calls
, 354, 54.77, , , ,
, .71 per execution
1864 @2, GGS , STAT, recursive calls
, 227, 35.12, , , ,
, 88.11us recursive CPU per recursive call
1864 @2, GGS , STAT, recursive cpu usage
, 2, .31, , , ,
, 20ms total recursive CPU usage
1864 @2, GGS , STAT, session logical reads
, 8347, 1.29k, , , ,
, 8.39k total buffer visits
1864 @2, GGS , STAT, CPU used when call started
, 11, 1.7, , , ,
, 110ms total CPU used when call started
1864 @2, GGS , STAT, CPU used by this session
, 11, 1.7, , , ,
, 110ms total CPU used by this session
1864 @2, GGS , STAT, DB time
, 642, 99.32, , , ,
, 1.28 per execution
1864 @2, GGS , STAT, cluster wait time
, 5, .77, , , ,
, .01 per execution
1864 @2, GGS , STAT, concurrency wait time
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, user I/O wait time
, 614, 94.99, , , ,
, 1.22 per execution
1864 @2, GGS , STAT, non-idle wait time
, 620, 95.92, , , ,
, 1.24 per execution
1864 @2, GGS , STAT, non-idle wait count
, 1347, 208.39, , , ,
, 2.68 per execution
1864 @2, GGS , STAT, messages sent
, 31, 4.8, , , ,
, .06 per execution
1864 @2, GGS , STAT, session pga memory
, 131072, 20.28k, , , ,
, 131.07k actual value in end of snapshot
1864 @2, GGS , STAT, enqueue waits
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, enqueue requests
, 45, 6.96, , , ,
, .09 per execution
1864 @2, GGS , STAT, enqueue releases
, 43, 6.65, , , ,
, .09 per execution
1864 @2, GGS , STAT, global enqueue gets sync
, 33, 5.11, , , ,
, .07 per execution
1864 @2, GGS , STAT, global enqueue releases
, 31, 4.8, , , ,
, .06 per execution
1864 @2, GGS , STAT, physical read total IO requests
, 348, 53.84, , , ,
, .69 per execution
1864 @2, GGS , STAT, physical read total bytes
, 2850816, 441.04k, , , ,
, 5.68k per execution
1864 @2, GGS , STAT, cell physical IO interconnect bytes
, 2850816, 441.04k, , , ,
, 5.68k per execution
1864 @2, GGS , STAT, gcs messages sent
, 290, 44.87, , , ,
, .58 per execution
1864 @2, GGS , STAT, ges messages sent
, 6, .93, , , ,
, .01 per execution
1864 @2, GGS , STAT, db block gets
, 7431, 1.15k, , , ,
, 14.8 per execution
1864 @2, GGS , STAT, db block gets from cache
, 7431, 1.15k, , , ,
, 14.8 per execution
1864 @2, GGS , STAT, db block gets from cache (fastpath)
, 1925, 297.81, , , ,
, 3.83 per execution
1864 @2, GGS , STAT, consistent gets
, 916, 141.71, , , ,
, 1.82 per execution
1864 @2, GGS , STAT, consistent gets from cache
, 916, 141.71, , , ,
, 1.82 per execution
1864 @2, GGS , STAT, consistent gets from cache (fastpath)
, 419, 64.82, , , ,
, .83 per execution
1864 @2, GGS , STAT, consistent gets - examination
, 446, 69, , , ,
, .89 per execution
1864 @2, GGS , STAT, logical read bytes from cache
, 68386816, 10.58M, , , ,
, 136.23k per execution
1864 @2, GGS , STAT, physical reads
, 348, 53.84, , , ,
, .69 per execution
1864 @2, GGS , STAT, physical reads cache
, 348, 53.84, , , ,
, .69 per execution
1864 @2, GGS , STAT, physical read IO requests
, 348, 53.84, , , ,
, 8.19k bytes per request
1864 @2, GGS , STAT, physical read bytes
, 2850816, 441.04k, , , ,
, 5.68k per execution
1864 @2, GGS , STAT, db block changes
, 4444, 687.52, , , ,
, 8.85 per execution
1864 @2, GGS , STAT, consistent changes
, 8, 1.24, , , ,
, .02 per execution
1864 @2, GGS , STAT, free buffer requested
, 475, 73.49, , , ,
, .95 per execution
1864 @2, GGS , STAT, hot buffers moved to head of LRU
, 925, 143.1, , , ,
, 1.84 per execution
1864 @2, GGS , STAT, free buffer inspected
, 694, 107.37, , , ,
, 1.38 per execution
1864 @2, GGS , STAT, commit cleanout failures: block lost
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, commit cleanout failures: callback failure
, 44, 6.81, , , ,
, .09 per execution
1864 @2, GGS , STAT, commit cleanouts
, 900, 139.24, , , ,
, 1.79 per execution
1864 @2, GGS , STAT, commit cleanouts successfully completed
, 855, 132.27, , , ,
, 1.7 per execution
1864 @2, GGS , STAT, switch current to new buffer
, 34, 5.26, , , ,
, .07 per execution
1864 @2, GGS , STAT, shared hash latch upgrades - no wait
, 10, 1.55, , , ,
, .02 per execution
1864 @2, GGS , STAT, calls to kcmgcs
, 98, 15.16, , , ,
, .2 per execution
1864 @2, GGS , STAT, calls to kcmgas
, 125, 19.34, , , ,
, .25 per execution
1864 @2, GGS , STAT, calls to get snapshot scn: kcmgss
, 346, 53.53, , , ,
, .69 per execution
1864 @2, GGS , STAT, redo entries
, 2566, 396.98, , , ,
, 5.11 per execution
1864 @2, GGS , STAT, redo size
, 1261700, 195.19k, , , ,
, 1.26M bytes per user commit
1864 @2, GGS , STAT, redo ordering marks
, 73, 11.29, , , ,
, .15 per execution
1864 @2, GGS , STAT, redo subscn max counts
, 3, .46, , , ,
, .01 per execution
1864 @2, GGS , STAT, file io wait time
, 6006037, 929.18k, , , ,
, 17.26ms bad guess of IO wait time per IO request
1864 @2, GGS , STAT, gc cr blocks received
, 3, .46, , , ,
, .01 per execution
1864 @2, GGS , STAT, gc current blocks received
, 14, 2.17, , , ,
, .03 per execution
1864 @2, GGS , STAT, gc local grants
, 214, 33.11, , , ,
, .43 per execution
1864 @2, GGS , STAT, gc remote grants
, 273, 42.24, , , ,
, .54 per execution
1864 @2, GGS , STAT, undo change vector size
, 422032, 65.29k, , , ,
, 840.7 per execution
1864 @2, GGS , STAT, no work - consistent read gets
, 417, 64.51, , , ,
, .83 per execution
1864 @2, GGS , STAT, cleanouts only - consistent read gets
, 2, .31, , , ,
, 0 per execution
1864 @2, GGS , STAT, RowCR attempts
, 3, .46, , , ,
, .01 per execution
1864 @2, GGS , STAT, RowCR hits
, 2, .31, , , ,
, 0 per execution
1864 @2, GGS , STAT, RowCR - row contention
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, immediate (CURRENT) block cleanout applications
, 69, 10.67, , , ,
, .14 per execution
1864 @2, GGS , STAT, immediate (CR) block cleanout applications
, 2, .31, , , ,
, 0 per execution
1864 @2, GGS , STAT, deferred (CURRENT) block cleanout applications
, 198, 30.63, , , ,
, .39 per execution
1864 @2, GGS , STAT, commit txn count during cleanout
, 48, 7.43, , , ,
, .1 per execution
1864 @2, GGS , STAT, active txn count during cleanout
, 31, 4.8, , , ,
, .06 per execution
1864 @2, GGS , STAT, cleanout - number of ktugct calls
, 43, 6.65, , , ,
, .09 per execution
1864 @2, GGS , STAT, Commit SCN cached
, 7, 1.08, , , ,
, .01 per execution
1864 @2, GGS , STAT, Block Cleanout Optim referenced
, 61, 9.44, , , ,
, .12 per execution
1864 @2, GGS , STAT, min active SCN optimization applied on CR
, 2, .31, , , ,
, 0 per execution
1864 @2, GGS , STAT, commit wait/nowait requested
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, commit nowait requested
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, commit wait/nowait performed
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, commit nowait performed
, 1, .15, , , ,
, 0 per execution
1864 @2, GGS , STAT, table fetch by rowid
, 88, 13.61, , , ,
, .18 per execution
1864 @2, GGS , STAT, table fetch continued row
, 11, 1.7, , , ,
, .02 per execution
1864 @2, GGS , STAT, cluster key scans
, 113, 17.48, , , ,
, .23 per execution
1864 @2, GGS , STAT, cluster key scan block gets
, 244, 37.75, , , ,
, .49 per execution
1864 @2, GGS , STAT, index crx upgrade (positioned)
, 4, .62, , , ,
, .01 per execution
1864 @2, GGS , STAT, leaf node splits
, 20, 3.09, , , ,
, .04 per execution
1864 @2, GGS , STAT, lob writes
, 56, 8.66, , , ,
, .11 per execution
1864 @2, GGS , STAT, lob writes unaligned
, 56, 8.66, , , ,
, .11 per execution
1864 @2, GGS , STAT, index fetch by key
, 149, 23.05, , , ,
, .3 per execution
1864 @2, GGS , STAT, index scans kdiixs1
, 89, 13.77, , , ,
, .18 per execution
1864 @2, GGS , STAT, HSC Heap Segment Block Changes
, 340, 52.6, , , ,
, .68 per execution
1864 @2, GGS , STAT, sql area evicted
, 3, .46, , , ,
, .01 per execution
1864 @2, GGS , STAT, session cursor cache hits
, 164, 25.37, , , ,
, 155 softparses avoided thanks to cursor cache
1864 @2, GGS , STAT, session cursor cache count
, -1, -.15, , , ,
, 0 per execution
1864 @2, GGS , STAT, buffer is pinned count
, 40, 6.19, , , ,
, .48 % buffer gets avoided thanks to buffer pin caching
1864 @2, GGS , STAT, buffer is not pinned count
, 648, 100.25, , , ,
, 1.29 per execution
1864 @2, GGS , STAT, workarea executions - optimal
, 22, 3.4, , , ,
, .04 per execution
1864 @2, GGS , STAT, parse count (total)
, 9, 1.39, , , ,
, 4.5 softparses per hardparse
1864 @2, GGS , STAT, parse count (hard)
, 2, .31, , , ,
, 0 per execution
1864 @2, GGS , STAT, execute count
, 502, 77.66, , , ,
, 55.78 executions per parse
1864 @2, GGS , STAT, bytes sent via SQL*Net to client
, 59813, 9.25k, , , ,
, 172.87 bytes per roundtrip
1864 @2, GGS , STAT, bytes received via SQL*Net from client
, 365977, 56.62k, , , ,
, 1.06k bytes per roundtrip
1864 @2, GGS , STAT, SQL*Net roundtrips to/from client
, 346, 53.53, , , ,
, .69 per execution
1864 @2, GGS , STAT, sorts (memory)
, 113, 17.48, , , ,
, .23 per execution
1864 @2, GGS , STAT, sorts (rows)
, 1956, 302.61, , , ,
, 3.9 per execution
1864 @2, GGS , TIME, hard parse elapsed time
, 415861, 64.34ms, 6.4%, [# ], ,
,
1864 @2, GGS , TIME, repeated bind elapsed time
, 729, 112.78us, .0%, [ ], ,
,
1864 @2, GGS , TIME, parse time elapsed
, 416409, 64.42ms, 6.4%, [# ], ,
,
1864 @2, GGS , TIME, DB CPU
, 242964, 37.59ms, 3.8%, [@ ], ,
,
1864 @2, GGS , TIME, sql execute elapsed time
, 6125962, 947.73ms, 94.8%, [##########], ,
,
1864 @2, GGS , TIME, DB time
, 6141266, 950.1ms, 95.0%, [##########], ,
, 3.45 % unaccounted time
1864 @2, GGS , WAIT, db file sequential read
, 5901443, 913ms, 91.3%, [WWWWWWWWWW], 362,
56, 16.3ms average wait
1864 @2, GGS , WAIT, gc cr block 2-way
, 192, 29.7us, .0%, [ ], 1,
.15, 192us average wait
1864 @2, GGS , WAIT, gc current block 2-way
, 959, 148.36us, .0%, [ ], 6,
.93, 159.83us average wait
1864 @2, GGS , WAIT, gc current block busy
, 805, 124.54us, .0%, [ ], 2,
.31, 402.5us average wait
1864 @2, GGS , WAIT, gc cr grant 2-way
, 2469, 381.97us, .0%, [ ], 23,
3.56, 107.35us average wait
1864 @2, GGS , WAIT, gc cr grant congested
, 461, 71.32us, .0%, [ ], 1,
.15, 461us average wait
1864 @2, GGS , WAIT, gc current grant 2-way
, 16348, 2.53ms, .3%, [ ], 129,
19.96, 126.73us average wait
1864 @2, GGS , WAIT, gc current grant busy
, 35577, 5.5ms, .6%, [W ], 125,
19.34, 284.62us average wait
1864 @2, GGS , WAIT, gc current grant congested
, 128, 19.8us, .0%, [ ], 1,
.15, 128us average wait
1864 @2, GGS , WAIT, row cache lock
, 5612, 868.22us, .1%, [ ], 28,
4.33, 200.43us average wait
1864 @2, GGS , WAIT, library cache pin
, 479, 74.1us, .0%, [ ], 3,
.46, 159.67us average wait
1864 @2, GGS , WAIT, library cache lock
, 321, 49.66us, .0%, [ ], 2,
.31, 160.5us average wait
1864 @2, GGS , WAIT, SQL*Net message to client
, 595, 92.05us, .0%, [ ], 366,
56.62, 1.63us average wait
1864 @2, GGS , WAIT, SQL*Net message from client
, 99311, 15.36ms, 1.5%, [W ], 365,
56.47, 272.08us average wait
-- End of Stats snap 1, end=2018-12-20 10:47:19, seconds=6.5
---------------------------------------------------------------------------------------------------------------
ActSes %Thread | INST | SQL_ID | SQL_CHILD | EVENT
| WAIT_CLASS
---------------------------------------------------------------------------------------------------------------
.54 (54%) | 2 | g4cf65js6kjf0 | 0 | db file sequential
read | User I/O
.18 (18%) | 2 | 43dvz166uqtkq | 0 | db file sequential
read | User I/O
.13 (13%) | 2 | gabtdu60mta41 | 1 | db file sequential
read | User I/O
.05 (5%) | 2 | 0s6zmhwfkuxwf | 0 | db file sequential
read | User I/O
.03 (3%) | 2 | 7a5tppp6fph0s | 1 | db file sequential
read | User I/O
.03 (3%) | 2 | 9v9vx2tqfy8rq | 0 | db file sequential
read | User I/O
.03 (3%) | 2 | gabtdu60mta41 | 1 | gc current request
| Cluster
.03 (3%) | 2 | 5wc19gh3h1cuc | 0 | db file sequential
read | User I/O
-- End of ASH snap 1, end=2018-12-20 10:47:19, seconds=5, samples_taken=39,
AAS=1
SQL> @snapper stats,ash 5 1 module=OGG-R1_825B-OPEN_DATA_SOURCE@2
Sampling SID module=OGG-R1_825B-OPEN_DATA_SOURCE@2 with interval 5 seconds,
taking 1 snapshots...
-- Session Snapper v4.24 - by Tanel Poder ( http://blog.tanelpoder.com/snapper ;
) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :)
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SID @INST, USERNAME , TYPE, STATISTIC
, DELTA, HDELTA/SEC, %TIME, GRAPH , NUM_WAITS,
WAITS/SEC, AVERAGES
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
1864 @2, GGS , STAT, Requests to/from client
, 337, 56.09, , , ,
, .99 per execution
1864 @2, GGS , STAT, opened cursors cumulative
, 3, .5, , , ,
, .01 per execution
1864 @2, GGS , STAT, user calls
, 340, 56.58, , , ,
, 1 per execution
1864 @2, GGS , STAT, recursive calls
, 1, .17, , , ,
, 0 recursive CPU per recursive call
1864 @2, GGS , STAT, session logical reads
, 7594, 1.26k, , , ,
, 7.62k total buffer visits
1864 @2, GGS , STAT, CPU used when call started
, 16, 2.66, , , ,
, 160ms total CPU used when call started
1864 @2, GGS , STAT, CPU used by this session
, 16, 2.66, , , ,
, 160ms total CPU used by this session
1864 @2, GGS , STAT, DB time
, 594, 98.86, , , ,
, 1.75 per execution
1864 @2, GGS , STAT, cluster wait time
, 7, 1.16, , , ,
, .02 per execution
1864 @2, GGS , STAT, concurrency wait time
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, user I/O wait time
, 559, 93.03, , , ,
, 1.65 per execution
1864 @2, GGS , STAT, non-idle wait time
, 566, 94.2, , , ,
, 1.67 per execution
1864 @2, GGS , STAT, non-idle wait count
, 1402, 233.33, , , ,
, 4.14 per execution
1864 @2, GGS , STAT, enqueue requests
, 29, 4.83, , , ,
, .09 per execution
1864 @2, GGS , STAT, enqueue releases
, 23, 3.83, , , ,
, .07 per execution
1864 @2, GGS , STAT, global enqueue gets sync
, 12, 2, , , ,
, .04 per execution
1864 @2, GGS , STAT, global enqueue releases
, 6, 1, , , ,
, .02 per execution
1864 @2, GGS , STAT, physical read total IO requests
, 356, 59.25, , , ,
, 1.05 per execution
1864 @2, GGS , STAT, physical read total bytes
, 2916352, 485.36k, , , ,
, 8.6k per execution
1864 @2, GGS , STAT, cell physical IO interconnect bytes
, 2916352, 485.36k, , , ,
, 8.6k per execution
1864 @2, GGS , STAT, gcs messages sent
, 329, 54.75, , , ,
, .97 per execution
1864 @2, GGS , STAT, ges messages sent
, 3, .5, , , ,
, .01 per execution
1864 @2, GGS , STAT, db block gets
, 7373, 1.23k, , , ,
, 21.75 per execution
1864 @2, GGS , STAT, db block gets from cache
, 7373, 1.23k, , , ,
, 21.75 per execution
1864 @2, GGS , STAT, db block gets from cache (fastpath)
, 1903, 316.71, , , ,
, 5.61 per execution
1864 @2, GGS , STAT, consistent gets
, 221, 36.78, , , ,
, .65 per execution
1864 @2, GGS , STAT, consistent gets from cache
, 221, 36.78, , , ,
, .65 per execution
1864 @2, GGS , STAT, consistent gets from cache (fastpath)
, 66, 10.98, , , ,
, .19 per execution
1864 @2, GGS , STAT, consistent gets - examination
, 150, 24.96, , , ,
, .44 per execution
1864 @2, GGS , STAT, logical read bytes from cache
, 62210048, 10.35M, , , ,
, 183.51k per execution
1864 @2, GGS , STAT, physical reads
, 356, 59.25, , , ,
, 1.05 per execution
1864 @2, GGS , STAT, physical reads cache
, 356, 59.25, , , ,
, 1.05 per execution
1864 @2, GGS , STAT, physical read IO requests
, 356, 59.25, , , ,
, 8.19k bytes per request
1864 @2, GGS , STAT, physical read bytes
, 2916352, 485.36k, , , ,
, 8.6k per execution
1864 @2, GGS , STAT, db block changes
, 4456, 741.6, , , ,
, 13.14 per execution
1864 @2, GGS , STAT, change write time
, 5, .83, , , ,
, .01 per execution
1864 @2, GGS , STAT, free buffer requested
, 466, 77.55, , , ,
, 1.37 per execution
1864 @2, GGS , STAT, dirty buffers inspected
, 3, .5, , , ,
, .01 per execution
1864 @2, GGS , STAT, hot buffers moved to head of LRU
, 1341, 223.18, , , ,
, 3.96 per execution
1864 @2, GGS , STAT, free buffer inspected
, 884, 147.12, , , ,
, 2.61 per execution
1864 @2, GGS , STAT, commit cleanouts
, 63, 10.48, , , ,
, .19 per execution
1864 @2, GGS , STAT, commit cleanouts successfully completed
, 63, 10.48, , , ,
, .19 per execution
1864 @2, GGS , STAT, switch current to new buffer
, 31, 5.16, , , ,
, .09 per execution
1864 @2, GGS , STAT, shared hash latch upgrades - no wait
, 2, .33, , , ,
, .01 per execution
1864 @2, GGS , STAT, calls to kcmgcs
, 99, 16.48, , , ,
, .29 per execution
1864 @2, GGS , STAT, calls to kcmgas
, 122, 20.3, , , ,
, .36 per execution
1864 @2, GGS , STAT, calls to get snapshot scn: kcmgss
, 151, 25.13, , , ,
, .45 per execution
1864 @2, GGS , STAT, redo entries
, 2574, 428.38, , , ,
, 7.59 per execution
1864 @2, GGS , STAT, redo size
, 1272112, 211.71k, , , ,
, ~ bytes per user commit
1864 @2, GGS , STAT, redo ordering marks
, 73, 12.15, , , ,
, .22 per execution
1864 @2, GGS , STAT, redo subscn max counts
, 2, .33, , , ,
, .01 per execution
1864 @2, GGS , STAT, file io wait time
, 5588159, 930.02k, , , ,
, 15.7ms bad guess of IO wait time per IO request
1864 @2, GGS , STAT, gc current blocks received
, 5, .83, , , ,
, .01 per execution
1864 @2, GGS , STAT, gc local grants
, 226, 37.61, , , ,
, .67 per execution
1864 @2, GGS , STAT, gc remote grants
, 325, 54.09, , , ,
, .96 per execution
1864 @2, GGS , STAT, undo change vector size
, 432192, 71.93k, , , ,
, 1.27k per execution
1864 @2, GGS , STAT, no work - consistent read gets
, 31, 5.16, , , ,
, .09 per execution
1864 @2, GGS , STAT, cleanouts only - consistent read gets
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, RowCR attempts
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, RowCR hits
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, immediate (CURRENT) block cleanout applications
, 73, 12.15, , , ,
, .22 per execution
1864 @2, GGS , STAT, immediate (CR) block cleanout applications
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, deferred (CURRENT) block cleanout applications
, 231, 38.44, , , ,
, .68 per execution
1864 @2, GGS , STAT, commit txn count during cleanout
, 38, 6.32, , , ,
, .11 per execution
1864 @2, GGS , STAT, active txn count during cleanout
, 36, 5.99, , , ,
, .11 per execution
1864 @2, GGS , STAT, cleanout - number of ktugct calls
, 36, 5.99, , , ,
, .11 per execution
1864 @2, GGS , STAT, Block Cleanout Optim referenced
, 67, 11.15, , , ,
, .2 per execution
1864 @2, GGS , STAT, min active SCN optimization applied on CR
, 2, .33, , , ,
, .01 per execution
1864 @2, GGS , STAT, table fetch by rowid
, 31, 5.16, , , ,
, .09 per execution
1864 @2, GGS , STAT, leaf node splits
, 21, 3.49, , , ,
, .06 per execution
1864 @2, GGS , STAT, lob writes
, 50, 8.32, , , ,
, .15 per execution
1864 @2, GGS , STAT, lob writes unaligned
, 50, 8.32, , , ,
, .15 per execution
1864 @2, GGS , STAT, index fetch by key
, 30, 4.99, , , ,
, .09 per execution
1864 @2, GGS , STAT, index scans kdiixs1
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, HSC Heap Segment Block Changes
, 340, 56.58, , , ,
, 1 per execution
1864 @2, GGS , STAT, sql area evicted
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, buffer is pinned count
, 30, 4.99, , , ,
, .39 % buffer gets avoided thanks to buffer pin caching
1864 @2, GGS , STAT, buffer is not pinned count
, 93, 15.48, , , ,
, .27 per execution
1864 @2, GGS , STAT, parse count (total)
, 3, .5, , , ,
, 3 softparses per hardparse
1864 @2, GGS , STAT, parse count (hard)
, 1, .17, , , ,
, 0 per execution
1864 @2, GGS , STAT, execute count
, 339, 56.42, , , ,
, 113 executions per parse
1864 @2, GGS , STAT, bytes sent via SQL*Net to client
, 58703, 9.77k, , , ,
, 173.17 bytes per roundtrip
1864 @2, GGS , STAT, bytes received via SQL*Net from client
, 352913, 58.73k, , , ,
, 1.04k bytes per roundtrip
1864 @2, GGS , STAT, SQL*Net roundtrips to/from client
, 339, 56.42, , , ,
, 1 per execution
1864 @2, GGS , TIME, hard parse elapsed time
, 4562, 759.24us, .1%, [ ], ,
,
1864 @2, GGS , TIME, repeated bind elapsed time
, 1539, 256.13us, .0%, [ ], ,
,
1864 @2, GGS , TIME, parse time elapsed
, 4690, 780.54us, .1%, [ ], ,
,
1864 @2, GGS , TIME, DB CPU
, 224965, 37.44ms, 3.7%, [@ ], ,
,
1864 @2, GGS , TIME, sql execute elapsed time
, 5735589, 954.55ms, 95.5%, [##########], ,
,
1864 @2, GGS , TIME, DB time
, 5717208, 951.49ms, 95.1%, [##########], ,
, 3.28 % unaccounted time
1864 @2, GGS , WAIT, db file sequential read
, 5485206, 912.88ms, 91.3%, [WWWWWWWWWW], 353,
58.75, 15.54ms average wait
1864 @2, GGS , WAIT, gc current block busy
, 838, 139.47us, .0%, [ ], 2,
.33, 419us average wait
1864 @2, GGS , WAIT, gc cr grant 2-way
, 475, 79.05us, .0%, [ ], 4,
.67, 118.75us average wait
1864 @2, GGS , WAIT, gc current grant 2-way
, 19205, 3.2ms, .3%, [ ], 144,
23.97, 133.37us average wait
1864 @2, GGS , WAIT, gc current grant busy
, 52677, 8.77ms, .9%, [W ], 178,
29.62, 295.94us average wait
1864 @2, GGS , WAIT, library cache pin
, 437, 72.73us, .0%, [ ], 2,
.33, 218.5us average wait
1864 @2, GGS , WAIT, library cache lock
, 218, 36.28us, .0%, [ ], 1,
.17, 218us average wait
1864 @2, GGS , WAIT, SQL*Net message to client
, 551, 91.7us, .0%, [ ], 347,
57.75, 1.59us average wait
1864 @2, GGS , WAIT, SQL*Net message from client
, 94470, 15.72ms, 1.6%, [W ], 347,
57.75, 272.25us average wait
-- End of Stats snap 1, end=2018-12-20 10:48:45, seconds=6
---------------------------------------------------------------------------------------------------------------
ActSes %Thread | INST | SQL_ID | SQL_CHILD | EVENT
| WAIT_CLASS
---------------------------------------------------------------------------------------------------------------
.49 (49%) | 2 | g4cf65js6kjf0 | 0 | db file sequential
read | User I/O
.14 (14%) | 2 | gabtdu60mta41 | 1 | db file sequential
read | User I/O
.11 (11%) | 2 | 43dvz166uqtkq | 0 | db file sequential
read | User I/O
.11 (11%) | 2 | 0s6zmhwfkuxwf | 0 | db file sequential
read | User I/O
.03 (3%) | 2 | g4cf65js6kjf0 | 0 | gc current request
| Cluster
.03 (3%) | 2 | dk114scy1su3r | 0 | db file sequential
read | User I/O
.03 (3%) | 2 | 43p1r78vagfby | 0 | db file sequential
read | User I/O
.03 (3%) | 2 | 2mb7g4w5wfk26 | 0 | ON CPU
| ON CPU
.03 (3%) | 2 | 5cfxg3dqppqj0 | 0 | db file sequential
read | User I/O
-- End of ASH snap 1, end=2018-12-20 10:48:45, seconds=5, samples_taken=35,
AAS=1
