‘latch: cache buffers chains’ & Don’t underestimate the rownum = 1
Last week, A database performance problems just written a short blog here now
# ASH report
Top User Events DB/Inst: ISAPDB/isapdb (Mar 02 10:49 to 11:04) Avg Active Event Event Class % Activity Sessions ----------------------------------- --------------- ---------- ---------- CPU + Wait for CPU CPU 21.64 41.99 log file sync Commit 21.63 41.97 enq: TX - row lock contention Application 19.71 38.23 buffer busy waits Concurrency 5.86 11.36 latch: cache buffers chains Concurrency 5.30 10.29 ------------------------------------------------------------- Distinct Avg Active SQL Command Type SQLIDs % Activity Sessions ---------------------------------------- ---------- ---------- ---------- UPDATE 25 22.39 43.44 SELECT 389 20.65 40.06 INSERT 33 16.02 31.09 DELETE 7 3.21 6.22 ------------------------------------------------------------- Top SQL Statements DB/Inst: ISAPDB/isapdb (Mar 02 10:49 to 11:04) SQL ID Planhash % Activity Event % Event ------------- ----------- ---------- ------------------------------ ---------- gzbvgw009x7gt 3559801910 10.62 enq: TX - row lock contention 10.36 update WL_PROCESS_INSTANCE set CREATE_DATE=:1, FINISH_DATE=:2, PROCESS_STATE_COD E=:3, PROCESS_VERSION_ID=:4, AREA_CODE=:5 where PROCESS_INSTANCE_ID=:6 7yz2wx6bvfv7n 2732114016 9.30 CPU + Wait for CPU 7.86 select * from wo_order_belong_type where order_id = :1 and rownum=1
Note:
The main performance problem was ‘index block split’ caused by large number of DML on same index blocks ,A large number of transactions commit and ‘log file sync’ ,Customer response a batch of the business running at this time,The optimization problem is not the scope of the discussion in this journal,but note the DB had latch CBC wait also , You can see that in addition to update, insert(batch job), There are also cost 40 percent of performance for ‘select’ operation,the SQL ID:7yz2wx6bvfv7n (select) in TOP SQL, it a simple sql,just return a few data (rownum = 1).
SQL> @?/rdbms/admin/sqltrpt 15 Most expensive SQL in the cursor cache ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ SQL_ID ELAPSED SQL_TEXT_FRAGMENT ------------- ---------- ------------------------------------------------------- 7yz2wx6bvfv7n ########## select * from wo_order_belong_type where order_id = :1 15 Most expensive SQL in the workload repository ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ SQL_ID ELAPSED SQL_TEXT_FRAGMENT ------------- ---------- -------------------------------------------------------------------- 7yz2wx6bvfv7n ########## select * from wo_order_belong_type where order_id = :1
# View the current execution plan
SQL_ID 7yz2wx6bvfv7n, child number 0 ------------------------------------- select * from wo_order_belong_type where order_id = :1 and rownum=1 Plan hash value: 2732114016 ------------------------------------------------------------ | Id | Operation | Name | E-Rows | ------------------------------------------------------------ |* 1 | COUNT STOPKEY | | | |* 2 | TABLE ACCESS FULL| WO_ORDER_BELONG_TYPE | 1 | ------------------------------------------------------------ Peeked Binds (identified by position): -------------------------------------- 1 - (NUMBER): 97892917 Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(ROWNUM=1) 2 - filter("ORDER_ID"=:1)
# ADDM RPT
RECOMMENDATION 2: SQL Tuning, 7.9% benefit (41869 seconds) ACTION: Run SQL Tuning Advisor on the SQL statement with SQL_ID "7yz2wx6bvfv7n". RELEVANT OBJECT: SQL statement with SQL_ID 7yz2wx6bvfv7n and PLAN_HASH 2732114016 select * from wo_order_belong_type where order_id = :1 and rownum=1 ACTION: Investigate the SQL statement with SQL_ID "7yz2wx6bvfv7n" for possible performance improvements. RELEVANT OBJECT: SQL statement with SQL_ID 7yz2wx6bvfv7n and PLAN_HASH 2732114016 select * from wo_order_belong_type where order_id = :1 and rownum=1 RATIONALE: SQL statement with SQL_ID "7yz2wx6bvfv7n" was executed 42138 times and had an average elapsed time of 0.99 seconds. RATIONALE: Waiting for event "latch: cache buffers chains" in wait class "Concurrency" accounted for 10% of the database time spent in processing the SQL statement with SQL_ID "7yz2wx6bvfv7n". RATIONALE: Average CPU used per execution was 0.37 seconds.
# enable sql trace ,Just specify an sql variable to view the execution plan manually.
SQL> select * from isap.wo_order_belong_type where order_id =1 and rownum=1; no rows selected Execution Plan ---------------------------------------------------------- Plan hash value: 3233662999 ----------------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ----------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 16 | 4 (0)| 00:00:01 | |* 1 | COUNT STOPKEY | | | | | | | 2 | TABLE ACCESS BY INDEX ROWID| WO_ORDER_BELONG_TYPE | 1 | 16 | 4 (0)| 00:00:01 | |* 3 | INDEX RANGE SCAN | IDX_ORDER_TYPE_ID | 1 | | 3 (0)| 00:00:01 | ----------------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(ROWNUM=1) 3 - access("ORDER_ID"=1) Statistics ---------------------------------------------------------- 1 recursive calls 0 db block gets 3 consistent gets 2 physical reads 0 redo size 531 bytes sent via SQL*Net to client 481 bytes received via SQL*Net from client 1 SQL*Net roundtrips to/from client 0 sorts (memory) 0 sorts (disk) 0 rows processed # full table scan SQL> select /*+no_index(t)*/* from isap.wo_order_belong_type t where order_id =1000 and rownum=1; no rows selected Execution Plan ---------------------------------------------------------- Plan hash value: 2732114016 ------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 16 | 2067 (3)| 00:00:25 | |* 1 | COUNT STOPKEY | | | | | | |* 2 | TABLE ACCESS FULL| WO_ORDER_BELONG_TYPE | 1 | 16 | 2067 (3)| 00:00:25 | ------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(ROWNUM=1) 2 - filter("ORDER_ID"=1000) Statistics ---------------------------------------------------------- 1 recursive calls 0 db block gets 9087 consistent gets 8 physical reads 0 redo size 531 bytes sent via SQL*Net to client 481 bytes received via SQL*Net from client 1 SQL*Net roundtrips to/from client 0 sorts (memory) 0 sorts (disk) 0 rows processed
NOTE:
INDEX FULL TABLE
CONS READ: 3 9087
COST : 4 2067
EST TIME : 1s 25s
To view the current active sessions wait event of running this sql .
select event ,status from v$session where sql_id='7yz2wx6bvfv7n'; EVENT STATUS ---------------------------------------------------------------- -------- latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE SQL*Net message from client ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE SQL*Net message from client ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE SQL*Net message from client ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE SQL*Net message from client ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE latch: cache buffers chains ACTIVE
#Then we can generate sql profile fixed in SQL execution plan to optimize the SQL ,After verifying again
SQL_ID 7yz2wx6bvfv7n, child number 1 ------------------------------------- select * from wo_order_belong_type where order_id = :1 and rownum=1 Plan hash value: 2118355954 ------------------------------------------------------------------------- | Id | Operation | Name | E-Rows | ------------------------------------------------------------------------- |* 1 | COUNT STOPKEY | | | | 2 | TABLE ACCESS BY INDEX ROWID| WO_ORDER_BELONG_TYPE | 1 | |* 3 | INDEX RANGE SCAN | PK_WO_ORDER_BELONG_TYPE | 1 | ------------------------------------------------------------------------- Peeked Binds (identified by position): -------------------------------------- 1 - (NUMBER): 98600749 Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(ROWNUM=1) 3 - access("ORDER_ID"=:1) Note ----- - SQL profile "coe_7yz2wx6bvfv7n_2118355954" used for this statement
对不起,这篇文章暂时关闭评论。