Tuesday, February 15, 2011

Tuning an inefficient SQL with semi-join

Found a sql look like the following in a batch job:

SELECT    
 distinct
 C.INT_PSEFS_ID
,C.ACCOUNT_ID
,C.PSEFS_ID
,C.IS_PQ
,C.psefs_save_date
FROM     
   MYSCH.PSEFS_MSTR A
  ,MYSCH.PSEFS_DTLS B
  ,MYSCH.PSEFS_MSTR C
WHERE    
    A.INT_PSEFS_ID = B.INT_PSEFS_ID
  AND C.PSEFS_ID LIKE SUBSTR (A.PSEFS_ID, 1, 13)|| '%'
  AND A.IS_VALID = 'N' 
  AND B.PSEFS_STATUS_ID IN (4, 6)
  AND A.PSEFS_COMP_DATE  <= SYSDATE - 45
;
The execution plan is as follows:
---------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name             | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                  |    66T|  4861T|       |  3064G  (2)|999:59:59 |
|   1 |  HASH UNIQUE                 |                  |    66T|  4861T|    11P|  3064G  (2)|999:59:59 |
|   2 |   TABLE ACCESS BY INDEX ROWID| PSEFS_MSTR       |  3287K|   122M|       |   149K  (1)| 00:29:49 |
|   3 |    NESTED LOOPS              |                  |    66T|  4861T|       |  3027G  (1)|999:59:59 |
|*  4 |     HASH JOIN                |                  |    20M|   794M|   550M|   839K  (3)| 02:47:49 |
|*  5 |      TABLE ACCESS FULL       | PSEFS_DTLS       |    26M|   250M|       |   612K  (2)| 02:02:29 |
|*  6 |      TABLE ACCESS FULL       | PSEFS_MSTR       |    20M|   600M|       |   156K  (6)| 00:31:17 |
|*  7 |     INDEX RANGE SCAN         | PSEFS_MSTR_IX5   |   591K|       |       |  5154   (1)| 00:01:02 |
---------------------------------------------------------------------------------------------------------


INT_PSEFS_ID is a PK of A, and a FK of B, so A join B on INT_PSEFS_ID will generate a result set (refer to as R1) with duplicated records of A; Then we selected out row of C (same table as A) by join it with R1t based on an unusual join condition with LIKE operator. To see the problem by way of example, supposing we have a row in C with PSRFS_ID='ABCDEFGHIJKLM_2'; In R1, we could have several rows with PSRFS_ID in('ABCDEFGHIJKLM_3', 'ABCDEFGHIJKLM_4', 'ABCDEFGHIJKLM_4', 'ABCDEFGHIJKLM'), due to the LIKE, the row in C will match 4 rows in R1, thus generate 4 duplicated rows in the final result set. I rewrote the SQL to use sub-queries to enable the more efficient semi-joins intead of normal joins
select 
C.INT_PSEFS_ID
, C.ACCOUNT_ID
, C.PSEFS_ID,IS_PQ
, C.psefs_save_date
from MYSCH.PSEFS_MSTR C
where
   SUBSTR(C.PSEFS_ID,1,13) in
   (
   select  SUBSTR(A.PSEFS_ID,1,13)
   from MYSCH.PSEFS_MSTR  A
    where  A.IS_VALID = 'N'
     and A.PSEFS_COMP_DATE  <= SYSDATE - 45 
     and exists ( select 1 from MYSCH.PSEFS_DTLS B
     where A.int_psefs_id = B.int_psefs_id
       and B.PSEFS_STATUS_ID IN (4, 6) )
   ) ;

Now the execution plan looks like:
------------------------------------------------------------------------------------------------
| Id  | Operation              | Name          | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT       |               |    26M|  1182M|       |  1174K  (3)| 03:54:49 |
|*  1 |  HASH JOIN RIGHT SEMI  |               |    26M|  1182M|   387M|  1174K  (3)| 03:54:49 |
|   2 |   VIEW                 | VW_NSO_1      |    20M|   155M|       |   839K  (3)| 02:47:49 |
|*  3 |    HASH JOIN RIGHT SEMI|               |    20M|   794M|   550M|   839K  (3)| 02:47:49 |
|*  4 |     TABLE ACCESS FULL  | PSEFS_DTLS    |    26M|   250M|       |   612K  (2)| 02:02:29 |
|*  5 |     TABLE ACCESS FULL  | PSEFS_MSTR    |    20M|   600M|       |   156K  (6)| 00:31:17 |
|   6 |   TABLE ACCESS FULL    | PSEFS_MSTR    |    65M|  2445M|       |   153K  (4)| 00:30:45 |
------------------------------------------------------------------------------------------------


Fig 1. Good query visual representation
           



Fig 2. Bad query visual representaion


Note: though this sql is actually rather simple, the visual approach advocated by Jonathan Lewis in this article really helps me to do the analysis

Monday, February 14, 2011

Open a HTML file from Cygwin command line

Cygwin allows me have a UNIX-link enviroment inside my Windows XP environment. As a Cygwin user, sometimes I would like to open a HTML file from Cygwin command line. To achieve this, first of all I create the following file and put under ~/bin.


---- start of ie.bat -----
@start "" /b "C:\Program Files\Internet Explorer\iexplore.exe" %*
---- end of ie.bat  ------


Secondly, in Cygwin, if we type pwd, we get UNIX-like current path name, i.e. with forward slashs, for example:
$ pwd
/cygdrive/c/Denis_Files/VZ2009

I need to convert it to Windows path name, so I create a shell script as follows:

$ cat ~/bin/pwdw
pwd | sed s#/cygdrive/c#c:# |sed  -e 's#\/#\\#g'


Now if I type 'pwdw' in the Cygwin command windows, I got:

$ pwdw
c:\Denis_Files\VZ2009

To start a HTML file, such as AWR report, what I need to do is:

ie.bat 'c:\Denis_Files\VZ2009\awrrpt_20101003_1300_1330.html'


Just a small tip that makes my life easier :-).

Wednesday, February 09, 2011

Quick notes about troubleshooting a blocker issue involving an insert

Called to help troubleshooting a production issue: an insert statemnt blocked many others. However, when I checked the database on 7:30 PM, the symptoms have gone.

In retrospective, the problem is most  likely due to a configuration issue in context of DMT. This database was upgraded to 10g a year ago from 8i. A few tablespaces is still dictionary-managed.


Here is the AWR "Top 5 Timed Events" during the problem period:

Top 5 Timed Events (18:30 -19:00)

Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class

enq: TX - contention 44,494 130,783 2,939 59.7 Other
enq: ST - contention 27,122 79,719 2,939 36.4 Configuration
CPU time 3,700 1.7
read by other session 839,265 2,843 3 1.3 User I/O
db file scattered read 405,142 2,121 5 1.0 User I/O


From: http://www.saptechies.com/faq-oracle-enqueues/,  we can read some info about Oracle enqueue.


System enqueues:

ST (space transaction enqueue): This enqueue is held in dictionary-managed tablespaces within extent allocations and releases.

TYPE = ST

Very large numbers of extents are allocated or deallocated.


You can solve the problem permanently by using LMTS instead of DMTS (refer to Notes 214995 and 659946). If you use DMTS, you must ensure that the extents of temporary segments, tables and indexes are sufficiently big so that you can avoid large quantities of extents being allocated and deallocated.




I wan able to find the blocker from the DBA_HIST_ACTIVE_SESS_HISTORY view. Drunig 18:30 - 19:00 Session 651 is blocking many other sessions, which either wait for enq: TX or enq:ST  for examples:

SAMPLE_TIME SESSION_ID SQL_ID EVENT BLOCKING_SESSION

---------------------------------------- ---------- ------------- ------------------------------ ----------------
08-FEB-11 06.59.56.243 PM 242 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 345 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 414 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 469 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 591 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 593 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 594 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 595 6wyrqa50whrjg enq: TX - contention 651
08-FEB-11 06.59.56.243 PM 596 6wyrqa50whrjg enq: TX - contention 651

...


SAMPLE_TIME SESSION_ID SQL_ID EVENT BLOCKING_SESSION
---------------------------------------- ---------- ------------- ------------------------------ ----------------
08-FEB-11 06.59.56.243 PM 1976 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 49 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1841 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1763 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1693 dpc1k1djg5gh0 enq: ST - contention 651
08-FEB-11 06.59.56.243 PM 1660 dpc1k1djg5gh0 enq: ST - contention 651

....

Session 651 that was doing the same insert lasted about 1hour, from about 6:17 to 7:15

SAMPLE_TIME SESSION_ID SQL_ID EVENT BLOCKING_SESSION
---------------------------------------- ---------- ------------- ------------------------------ ----------------
08-FEB-11 06.17.23.778 PM 651 6wyrqa50whrjg
08-FEB-11 06.17.33.998 PM 651 6wyrqa50whrjg
08-FEB-11 06.17.44.198 PM 651 6wyrqa50whrjg
08-FEB-11 06.17.54.508 PM 651 6wyrqa50whrjg
...

08-FEB-11 07.14.45.919 PM 651 6wyrqa50whrjg
08-FEB-11 07.14.56.049 PM 651 6wyrqa50whrjg
08-FEB-11 07.15.06.159 PM 651 6wyrqa50whrjg
-- end --



After this sql ( 6wyrqa50whrjg  is an  simple insert into a table) was done, things become normal.  I am still not sure why this insert took so long. I was unable to know what wait event it was experiencing. Apparantly, Oracle was allocating a new extent to the table segment, but why took about an hour? The table referred in the SQL has two extents now, first one has 64000 blocks, the second has 16000 blocks.

So the scenario appeared to be that a session wants to insert a row into a table that resides in a DMT tablespace, but  the table segment is run out of space, Oracle firstly has to allocate a new extent to the table segment; the session is waiting for this allocation to complete; it blocks all other sessions doing the same insert into the same table with the latter waiting for enq:TX. It also blocks other sessions with enq:ST events,  which  are doing DML on  different tables  that resides in the same tablespace.

Anyway we really need to migrate DMT to LMT asap.

Monday, January 10, 2011

Using analytical function rank() - an example of improving query performance

Today, I have encountered a sql in a production database, which looks like


select distinct rs, bid, 
     [some_other_cols ...  ]
  from
     prod_table n
   where ee_date in (
       select max(ee_date) from
                prod_table n1
           where n1.bid = n.bid
             and n1.cc = n.cc
             and n1.rs=n.rs)



---------------------------------------------------------------------------------------
| Id  | Operation             | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |               |   571 | 51390 |   197   (4)| 00:00:03 |
|   1 |  HASH UNIQUE          |               |   571 | 51390 |   197   (4)| 00:00:03 |
|*  2 |   FILTER              |               |       |       |            |          |
|   3 |    HASH GROUP BY      |               |   571 | 51390 |   197   (4)| 00:00:03 |
|*  4 |     HASH JOIN         |               | 22250 |  1955K|   194   (3)| 00:00:03 |
|   5 |      TABLE ACCESS FULL| PROD_TABLE    | 22250 |   738K|    96   (2)| 00:00:02 |
|   6 |      TABLE ACCESS FULL| PROD_TABLE    | 22250 |  1216K|    97   (3)| 00:00:02 |
---------------------------------------------------------------------------------------


It contains a correlated sub-query. I rewrote it by using the analytical function rank(). I found that the consistent gets reduced by half



select distinct rs,bid, 
     [some_other_cols ...  ]
    from
    (
    select  n1.*,
           rank() over ( partition by bid, cc, rs order by ee_date desc ) rank
    from  prod_table n1
    )
    where rank =1;


-------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name          | Rows  | Bytes |TempSpc| Cost (%CPU)| Time
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |               | 22250 |   956K|       |   602   (2)| 00:00:08
|   1 |  HASH UNIQUE              |               | 22250 |   956K|  2984K|   602   (2)| 00:00:08
|*  2 |   VIEW                    |               | 22250 |   956K|       |   350   (2)| 00:00:05
|*  3 |    WINDOW SORT PUSHED RANK|               | 22250 |   956K|  2984K|   350   (2)| 00:00:05
|   4 |     TABLE ACCESS FULL     | PROD_TABLE    | 22250 |   956K|       |    98   (4)| 00:00:02
-------------------------------------------------------------------------------------------------

Wednesday, October 20, 2010

Composite index selectivity

I did tests with 10053 trace today and found that Oracle CBO behavior changes regarding compute selectivity of 3-column composite index from 9.2.0.8 to 10.2.0.4. (note: no histogram on any columns)

In 9i: selectivty of index(col1, col2, col3)= density (co11) x denisty (col2) x denisity(col3);

In 10g and 11g selectivity of index(col1, col2, col3) = 1/DISTINCT_KEYS where DISTINCT_KEYS is from index stats obtainable through dba_indexes.


Here is the test case which mimics the production able and the problem sql.

----- begin of the test case ----

drop table test;
create table test
as
select level id,
       trunc(mod(level,80)) id1,
       20*trunc(mod(level, 40)) id2,
       1    id3,
       trunc(mod(level,50)) id4
from dual
connect by level <=1000000;


create index test_ix1 on test(id1, id2, id3);

exec dbms_stats.gather_table_stats(user,'test', method_opt=>'FOR ALL COLUMNS size 1', cascade=>true);


alter session set tracefile_identifier = test;
ALTER SESSION SET EVENTS='10053 trace name context forever, level 1';

explain plan for
select id
from test
where id1 = 20
and id3=1
and id2 = 400;

ALTER SESSION SET EVENTS '10053 trace name context off';
Exit
------ end of test case  -----------------------

#### 9.2.0.8  10053 trace excerpt


***************************************
SINGLE TABLE ACCESS PATH
Column:        ID1  Col#: 2      Table: TEST   Alias: TEST
    NDV: 80        NULLS: 0         DENS: 1.2500e-02 LO:  0  HI: 79
    NO HISTOGRAM: #BKT: 1 #VAL: 2
Column:        ID3  Col#: 4      Table: TEST   Alias: TEST
    NDV: 1         NULLS: 0         DENS: 1.0000e+00 LO:  1  HI: 1
    NO HISTOGRAM: #BKT: 1 #VAL: 2
Column:        ID2  Col#: 3      Table: TEST   Alias: TEST
    NDV: 40        NULLS: 0         DENS: 2.5000e-02 LO:  0  HI: 780
    NO HISTOGRAM: #BKT: 1 #VAL: 2
  TABLE: TEST     ORIG CDN: 1000000  ROUNDED CDN: 313  CMPTD CDN: 313
  Access path: tsc  Resc:  857  Resp:  847
  Access path: index (equal)
      Index: TEST_IX1
  TABLE: TEST
      RSC_CPU: 711380   RSC_IO: 82
  IX_SEL:  0.0000e+00  TB_SEL:  3.1250e-04
  BEST_CST: 83.00  PATH: 4  Degree:  1


#### 10.2.0.4  10053 trace excerpt

***************************************
SINGLE TABLE ACCESS PATH
  -----------------------------------------
  BEGIN Single Table Cardinality Estimation
  -----------------------------------------
  Column (#2): ID1(NUMBER)
    AvgLen: 3.00 NDV: 81 Nulls: 0 Density: 0.012346 Min: 0 Max: 79
  Column (#4): ID3(NUMBER)
    AvgLen: 3.00 NDV: 1 Nulls: 0 Density: 1 Min: 1 Max: 1
  Column (#3): ID2(NUMBER)
    AvgLen: 4.00 NDV: 40 Nulls: 0 Density: 0.025 Min: 0 Max: 780
  Table: TEST  Alias: TEST
    Card: Original: 1003092  Rounded: 310  Computed: 309.60  Non Adjusted: 309.60
  -----------------------------------------
  END   Single Table Cardinality Estimation
  -----------------------------------------
  Access Path: TableScan
    Cost:  730.88  Resp: 730.88  Degree: 0
      Cost_io: 700.00  Cost_cpu: 284170229
      Resp_io: 700.00  Resp_cpu: 284170229
  Access Path: index (AllEqRange)
    Index: TEST_IX1
    resc_io: 3173.00  resc_cpu: 27721329
    ix_sel: 0.0125  ix_sel_with_filters: 0.0125
    Cost: 3176.01  Resp: 3176.01  Degree: 1
  Best:: AccessPath: TableScan
         Cost: 730.88  Degree: 1  Resp: 730.88  Card: 309.60  Bytes: 0

Note:
select index_name, distinct_keys from user_indexes where index_name='TEST_IX1';

INDEX_NAME                     DISTINCT_KEYS
------------------------------ -------------
TEST_IX1                                  80


#### 11.2.0.1  10053 trace excerpt


***************************************
SINGLE TABLE ACCESS PATH
  Single Table Cardinality Estimation for TEST[TEST]
  ColGroup (#1, Index) TEST_IX1
    Col#: 2 3 4    CorStregth: 40.00
  ColGroup Usage:: PredCnt: 3  Matches Full: #1  Partial:  Sel: 0.0125
  Table: TEST  Alias: TEST
    Card: Original: 1000000.000000  Rounded: 12500  Computed: 12500.00  Non Adjusted: 12500.00
  Access Path: TableScan
    Cost:  629.80  Resp: 629.80  Degree: 0
      Cost_io: 617.00  Cost_cpu: 283372261
      Resp_io: 617.00  Resp_cpu: 283372261
  ColGroup Usage:: PredCnt: 3  Matches Full: #1  Partial:  Sel: 0.0125
  ColGroup Usage:: PredCnt: 3  Matches Full: #1  Partial:  Sel: 0.0125
  Access Path: index (AllEqRange)
    Index: TEST_IX1
    resc_io: 3173.00  resc_cpu: 27721329
    ix_sel: 0.012500  ix_sel_with_filters: 0.012500
    Cost: 3174.25  Resp: 3174.25  Degree: 1
  Best:: AccessPath: TableScan
         Cost: 629.80  Degree: 1  Resp: 629.80  Card: 12500.00  Bytes: 0


Notice the ix_sel line in the above 10053 trace excerpt; for 10g and 11g it equal to 1/80. for 9i seems computed through multiplying selectivity of eeach column.

Update:
Came accross Jonathan Lewis's comment, and came to know this CBO behavior changes acctually from 10.1.0.4 ie. 10.1.0.4 is still similar to 9i behavior.


Below is his comment: (http://kr.forums.oracle.com/forums/thread.jspa?messageID=3153224)

--------
For a single-table query with the predicate
(full list of index columns) = (set of values)

The selectivities vary across version as follows:

11.1.0.6: Table selectivity and index selectivity given by distinct_keys in index
10.2.0.1: Table selectivity given by product of column selectivities, index selectivity given by distinct_keys in index
10.1.0.4: Table selectivity and index selectivity given by product of column selectivities

------------

JL's original post about this behavior: http://jonathanlewis.wordpress.com/2008/03/11/everything-changes/