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