ANBOB™

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