December 20, 2012

Performance Shooting: How much can SEQUENCE slow down a SQL

How much can SEQUENCE drag down speed of SQL?
10%? 20%? Below my working case show you SEQUENCE drag down 600% speed of one SQL.

It is during my recently shooting of a job's performance issue, i notice this SQL in the job block.
This is quite a simple SQL, two tables join, only thing secial is that it is using a sequence GGGC_SSBA.SEQ_MIM_CCCC_PPPP_SSS.NEXTVAL:

dwxxxx2 > SELECT /*+ USE_HASH(S1 TM)*/    GGGC_SSBA.SEQ_MIM_CCCC_PPPP_SSS.NEXTVAL        ,330404
  ,TO_DATE('2012-12-18 06:45:18', 'YYYY-MM-DD HH24:MI:SS')
  ,TO_DATE('2012-12-18 06:45:18', 'YYYY-MM-DD HH24:MI:SS')
  ,TO_DATE('2100-12-31', 'YYYY-MM-DD')    ,S1.MATNR AS MATNR      ,S1.VKORG AS
  VKORG   ,S1.VTWEG AS VTWEG      ,S1.KONDM AS KONDM      ,S1.DWERK AS DWERK
  ,S1.VMSTA AS VMSTA      ,S1.VMSTD AS VMSTD      ,S1.LVORM AS LVORM
  ,S1.DT_TM_XTR AS DT_TM_XTR      ,S1.CDHDR_UDATE AS CDHDR_UDATE  
  ,S1.PROVG AS PROVG FROM    GEPC_TEMP_TABLE.KKK_MIM_XXXX_RRRR_SSS TM
  GEPC_SOURCE.EEEIE_ZZZZZ_MMML_SLS S1 WHERE      TM.SOURCE_ROWID = S1.ROWID;

643418 rows selected.
Elapsed: 00:01:00.21

Execution Plan
----------------------------------------------------------
Plan hash value: 3276368232
--------------------------------------------------------------------------------------------
| Id  | Operation           | Name                  | Rows  | Bytes | Cost (%CPU)| Time    |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |                       | 36837 |  2590K|   759   (3)| 00:00:14|
|   1 |  SEQUENCE           | SEQ_MIM_CCCC_PPPP_SSS |       |       |            |         |
|*  2 |   HASH JOIN         |                       | 36837 |  2590K|   759   (3)| 00:00:14|
|   3 |    TABLE ACCESS FULL| KKK_MIM_XXXX_RRRR_SSS | 36837 |   359K|    29   (0)| 00:00:01|
|   4 |    TABLE ACCESS FULL| EEEIE_ZZZZZ_MMML_SLS  |   643K|    38M|   724   (3)| 00:00:14|
--------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("TM"."SOURCE_ROWID"="S1".ROWID)

Statistics
----------------------------------------------------------
     128804  recursive calls
      96793  db block gets
      77309  consistent gets
        661  physical reads
   21141944  redo size
   25998756  bytes sent via SQL*Net to client
     472358  bytes received via SQL*Net from client
      42896  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
     643418  rows processed

From above red part we see the SQL esclape time is one minute.
That is too long after considerring the query's base tables data volumn, it should not take that much time.

We also notice that big "recursive calls" and "db block gets" Statistics.
It is very clear that they are caused by the sequence in the SQL.

So let's remove the sequence from the query and check again:
dwxxxx2 > SELECT /*+ USE_HASH(S1 TM)*/    330404
  ,TO_DATE('2012-12-18 06:45:18', 'YYYY-MM-DD HH24:MI:SS')
  ,TO_DATE('2012-12-18 06:45:18', 'YYYY-MM-DD HH24:MI:SS')
  ,TO_DATE('2100-12-31', 'YYYY-MM-DD')    ,S1.MATNR AS MATNR      ,S1.VKORG AS
  VKORG   ,S1.VTWEG AS VTWEG      ,S1.KONDM AS KONDM      ,S1.DWERK AS DWERK
  ,S1.VMSTA AS VMSTA      ,S1.VMSTD AS VMSTD      ,S1.LVORM AS LVORM
  ,S1.DT_TM_XTR AS DT_TM_XTR      ,S1.CDHDR_UDATE AS CDHDR_UDATE  
  ,S1.PROVG AS PROVG FROM    GEPC_TEMP_TABLE.KKK_MIM_XXXX_RRRR_SSS TM
  GEPC_SOURCE.EEEIE_ZZZZZ_MMML_SLS S1 WHERE      TM.SOURCE_ROWID = S1.ROWID;

643418 rows selected.
Elapsed: 00:00:10.23

Execution Plan
----------------------------------------------------------
Plan hash value: 2074598172
-------------------------------------------------------------------------------------------
| Id  | Operation          | Name                  | Rows  | Bytes | Cost (%CPU)| Time    |
-------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |                       | 36837 |  2590K|   759   (3)| 00:00:14|
|*  1 |  HASH JOIN         |                       | 36837 |  2590K|   759   (3)| 00:00:14|
|   2 |   TABLE ACCESS FULL| KKK_MIM_XXXX_RRRR_SSS | 36837 |   359K|    29   (0)| 00:00:01|
|   3 |   TABLE ACCESS FULL| EEEIE_ZZZZZ_MMML_SLS  |   643K|    38M|   724   (3)| 00:00:14|
-------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("TM"."SOURCE_ROWID"="S1".ROWID)

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
      44998  consistent gets
          0  physical reads
          0  redo size
   21501260  bytes sent via SQL*Net to client
     472358  bytes received via SQL*Net from client
      42896  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
     643418  rows processed

Without the sequence the job completes in 10 seconds.
In another word, the sequence drag down 600% speed of this SQL.

Let's check the sequence attribute:
dwxxxx2 >select * from dba_sequences where SEQUENCE_NAME='SEQ_MIM_CCCC_PPPP_SSS';
SEQUENCE_OWNER SEQUENCE_NAME         INCREMENT_BY C O CACHE_SIZE LAST_NUMBER
-------------- --------------------- ------------ - - ---------- -----------
GGGC_SSBA      SEQ_MIM_CCCC_PPPP_SSS            1 N N         20   109594869

The CACHE_SIZE is 20.
20 is a default value, it is not suitable in our case.
I increase the value to 500 and re-execute the SQL.

This time:
dwxxxx2 > SELECT /*+ USE_HASH(S1 TM)*/    GGGC_SSBA.SEQ_MIM_CCCC_PPPP_SSS.NEXTVAL        ,330404
  ,TO_DATE('2012-12-18 06:45:18', 'YYYY-MM-DD HH24:MI:SS')
  ,TO_DATE('2012-12-18 06:45:18', 'YYYY-MM-DD HH24:MI:SS')
  ,TO_DATE('2100-12-31', 'YYYY-MM-DD')    ,S1.MATNR AS MATNR      ,S1.VKORG AS
  VKORG   ,S1.VTWEG AS VTWEG      ,S1.KONDM AS KONDM      ,S1.DWERK AS DWERK
  ,S1.VMSTA AS VMSTA      ,S1.VMSTD AS VMSTD      ,S1.LVORM AS LVORM
  ,S1.DT_TM_XTR AS DT_TM_XTR      ,S1.CDHDR_UDATE AS CDHDR_UDATE  
  ,S1.PROVG AS PROVG FROM    GEPC_TEMP_TABLE.KKK_MIM_XXXX_RRRR_SSS TM
  GEPC_SOURCE.EEEIE_ZZZZZ_MMML_SLS S1 WHERE      TM.SOURCE_ROWID = S1.ROWID;

643418 rows selected.
Elapsed: 00:00:29.60

Execution Plan
----------------------------------------------------------
Plan hash value: 3276368232
--------------------------------------------------------------------------------------------
| Id  | Operation           | Name                  | Rows  | Bytes | Cost (%CPU)| Time    |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT    |                       | 36837 |  2590K|   759   (3)| 00:00:14|
|   1 |  SEQUENCE           | SEQ_MIM_CCCC_PPPP_SSS |       |       |            |         |
|*  2 |   HASH JOIN         |                       | 36837 |  2590K|   759   (3)| 00:00:14|
|   3 |    TABLE ACCESS FULL| KKK_MIM_XXXX_RRRR_SSS | 36837 |   359K|    29   (0)| 00:00:01|
|   4 |    TABLE ACCESS FULL| EEEIE_ZZZZZ_MMML_SLS  |   643K|    38M|   724   (3)| 00:00:14|
--------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("TM"."SOURCE_ROWID"="S1".ROWID)

Statistics
----------------------------------------------------------
       5153  recursive calls
       3870  db block gets
      46287  consistent gets
          0  physical reads
     844460  redo size
   25998756  bytes sent via SQL*Net to client
     472358  bytes received via SQL*Net from client
      42896  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
     643418  rows processed

SQL completes in 30 seconds. Also "db block gets" and "recursive calls" is much smaller then first serneriao--cache is 20.

30 seconds means still the sequence drag down 3 times of the sql's speed.
It is still not reasonable.
The DB have mutiple samiliar queries, I don't have enough free time to look deep into this. I may raise a ticket with oracle support to check this once i get free time.

0 Comments:

Post a Comment