Home » RDBMS Server » Performance Tuning » Lost Index from the second execution time (Oracle 11gR2, Windows 64 bit)
Lost Index from the second execution time [message #589910] Thu, 11 July 2013 22:55 Go to next message
trantuananh24hg
Messages: 619
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Dear!

First time, I'm sorry because my long topic cause convenience to you. So, I break it into 3 instead of 1 topic.

I've got one problem which took me a time to resolve, of course, I've not done still now.

The problem was describe:

- First time to execute: Using all indexes on 2 tables
- Second time to execute: Using only indexes on first table, full table scan on the other
- Third time to execute: Do FTS on both of tables.

Now, I show the objects and relate information here:

The Tables:

system@dbwap> select count(*) from my_wap.news_relation;

  COUNT(*)
----------
    272708

system@dbwap> select count(*) from my_wap.news_content;

  COUNT(*)
----------
     95092
	 
system@dbwap> desc my_wap.news_content;
 Name                                                  Null?    Type
 ----------------------------------------------------- -------- ----------------
 ID                                                    NOT NULL NUMBER(11)
 SUBJECT                                               NOT NULL VARCHAR2(500)
 TITLE                                                          VARCHAR2(4000)
 STATE                                                          NUMBER(1)
 IMGPATH                                                        VARCHAR2(500)
 ALIGN                                                          VARCHAR2(10)
 CONTENT                                                        LONG
 CREATE_TIME                                           NOT NULL DATE
 USERNAME                                              NOT NULL VARCHAR2(20)
 PUBLIC_TIME                                                    DATE
 PUBLIC_BY                                                      VARCHAR2(20)
 IMGDETAIL                                                      VARCHAR2(300)
 BEGIN_TIME                                                     DATE
 END_TIME                                                       DATE
 UPDATE_TIME                                           NOT NULL DATE
 UPDATE_BY                                             NOT NULL VARCHAR2(255)
 IS_VERIFY                                             NOT NULL NUMBER(1)
 IS_DELAY                                              NOT NULL NUMBER(1)
 DELAY_TIME                                            NOT NULL DATE

DBMS_METADATA.GET_DDL('TABLE','NEWS_CONTENT','MY_WAP')
--------------------------------------------------------------------------------


  CREATE TABLE "MY_WAP"."NEWS_CONTENT"
   (    "ID" NUMBER(11,0) NOT NULL ENABLE,
        "SUBJECT" VARCHAR2(500) NOT NULL ENABLE,
        "TITLE" VARCHAR2(4000),
        "STATE" NUMBER(1,0) DEFAULT 1,
        "IMGPATH" VARCHAR2(500),
        "ALIGN" VARCHAR2(10) DEFAULT 'left',
        "CONTENT" LONG,
        "CREATE_TIME" DATE DEFAULT sysdate NOT NULL ENABLE,
        "USERNAME" VARCHAR2(20) DEFAULT 'trungdh' NOT NULL ENABLE,
        "PUBLIC_TIME" DATE,
        "PUBLIC_BY" VARCHAR2(20),
        "IMGDETAIL" VARCHAR2(300),
        "BEGIN_TIME" DATE DEFAULT SYSDATE,
        "END_TIME" DATE DEFAULT SYSDATE,
        "UPDATE_TIME" DATE DEFAULT sysdate NOT NULL ENABLE,
        "UPDATE_BY" VARCHAR2(255) DEFAULT sysdate NOT NULL ENABLE,
        "IS_VERIFY" NUMBER(1,0) DEFAULT 0 NOT NULL ENABLE,
        "IS_DELAY" NUMBER(1,0) DEFAULT 0 NOT NULL ENABLE,
        "DELAY_TIME" DATE DEFAULT sysdate NOT NULL ENABLE,
         [b]CONSTRAINT "NEWS_CONTENT_PK" PRIMARY KEY ("ID")[/b]
  USING INDEX PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTICS
  STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT

 
system@dbwap> desc my_wap.news_relation;
 Name                                                  Null?    Type
 ----------------------------------------------------- -------- ----------------
 CATEGORY_ID                                           NOT NULL NUMBER(6)
 ICT_ID                                                NOT NULL NUMBER(11)
 ORDER_ID                                                       NUMBER(11)
 SHOW_HOMEPAGE                                                  NUMBER(1)

  CREATE TABLE "MY_WAP"."NEWS_RELATION"
   (    "CATEGORY_ID" NUMBER(6,0) NOT NULL ENABLE,
        "ICT_ID" NUMBER(11,0) NOT NULL ENABLE,
        "ORDER_ID" NUMBER(11,0) DEFAULT 0,
        "SHOW_HOMEPAGE" NUMBER(1,0) DEFAULT 0,
         [b]CONSTRAINT "NEWS_RELATION_UK" UNIQUE ("ICT_ID", "CATEGORY_ID")[/b]
  USING INDEX PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTICS
  STORAGE(INITIAL 2097152 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
  TABLESPACE "USERS"  ENABLE,
         [b]CONSTRAINT "NEWS_RELATION_PK" PRIMARY KEY ("CATEGORY_ID", "ICT_ID")[/b]
  USING INDEX PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTICS
  STORAGE(INITIAL 2097152 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
  TABLESPACE "USERS"  ENABLE
   ) SEGMENT CREATION IMMEDIATE
  PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255 NOCOMPRESS LOGGING
  STORAGE(INITIAL 2097152 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
  TABLESPACE "USERS"


You will see: I've got 2 tables names as NEWS_CONTENT and NEWS_RELATION

The Primary key from NEWS_CONTENT: ID column
The Primary key from NEWS_RELATION: Multiple columns CATEGORY_ID, ICT_ID
The table NEWS_CONTENT has got: 95092 rows
The table NEWS_RELATION has got: 272708 rows

Segment size:

OWNER      SEGMENT_NAME            MB
---------- --------------- ----------
MY_WAP     NEWS_RELATION            7
MY_WAP     NEWS_CONTENT           440


Index and statistics:

system@dbwap> col owner format a9
system@dbwap> col table_name format a16
system@dbwap> col ANALYZE format a37
OWNER     TABLE_NAME       ANALYZE
--------- ---------------- ----------------------------------
MY_WAP    NEWS_RELATION    10-07-2013 11:38:08
MY_WAP    NEWS_CONTENT     10-07-2013 11:35:09

OOWNER     TABLE_NAME       INDEX_NAME                  ANALYZE
--------- ---------------- --------------------------- --------------------
MY_WAP    NEWS_CONTENT     NEWS_CONTENT_PK             10-07-2013 11:35:09
MY_WAP    NEWS_CONTENT     NEWS_CONTENT_INDEX1         10-07-2013 11:35:09
MY_WAP    NEWS_CONTENT     INDX_BEGINTIME              10-07-2013 11:35:09
MY_WAP    NEWS_CONTENT     INDX_ENDTIME                10-07-2013 11:35:09
MY_WAP    NEWS_RELATION    IDX_CATEGORY_SHOWHOMEPAGE   10-07-2013 11:38:09
MY_WAP    NEWS_RELATION    NEWS_RELATION_UK            10-07-2013 11:38:16
MY_WAP    NEWS_RELATION    CATEGORY_INDEX1             10-07-2013 11:38:27
MY_WAP    NEWS_RELATION    ORDER_INDEX1                10-07-2013 11:38:29
MY_WAP    NEWS_RELATION    ICT_INDEX1                  10-07-2013 11:38:29
MY_WAP    NEWS_RELATION    INDX_SHOWHOMEPAGE           10-07-2013 11:38:30


Re: Lost Index from the second execution time [message #589911 is a reply to message #589910] Thu, 11 July 2013 22:57 Go to previous messageGo to next message
trantuananh24hg
Messages: 619
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
The SQL:

/* Formatted on 12-Jul-2013 10:25:14 (QP5 v5.126) */
SELECT   *
  FROM   (SELECT   ROWNUM stt,
                   id,
                   subject,
                   title,
                   imgpath,
                   imgdetail,
                   align,
                   tgian
            FROM   (  SELECT   id,
                               subject,
                               title,
                               imgpath,
                               imgdetail,
                               align,
                               TO_CHAR (public_time, 'dd-mm-yyyy hh24:mi:ss')
                                   tgian
                        FROM   my_wap.news_content a, my_wap.news_relation b
                       WHERE       a.begin_time < SYSDATE
                               AND SYSDATE < a.end_time
                               AND b.show_homepage = 1
                               AND (state = 0 OR state = 1)
                               AND b.category_id = 6282
                               AND b.ict_id = a.id
                    ORDER BY   b.order_id DESC))
 WHERE   stt > 5 AND stt <= 6
/
Re: Lost Index from the second execution time [message #589912 is a reply to message #589911] Thu, 11 July 2013 23:04 Go to previous messageGo to next message
trantuananh24hg
Messages: 619
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Nows, I trace the explain plan as a single session from my sql*plus:
system@dbwap> SELECT   *
  2    FROM   (SELECT   ROWNUM stt,
  3                     id,
  4                     subject,
  5                     title,
  6                     imgpath,
  7                     imgdetail,
  8                     align,
  9                     tgian
 10              FROM   (  SELECT   id,
 11                                 subject,
 12                                 title,
 13                                 imgpath,
 14                                 imgdetail,
 15                                 align,
 16                                 TO_CHAR (public_time, 'dd-mm-yyyy hh24:mi:ss
')
 17                                     tgian
 18                          FROM   my_wap.news_content a, my_wap.news_relation
b
 19                         WHERE       a.begin_time < SYSDATE
 20                                 AND SYSDATE < a.end_time
 21                                 AND b.show_homepage = 1
 22                                 AND (state = 0 OR state = 1)
 23                                 AND b.category_id = 6282
 24                                 AND b.ict_id = a.id
 25                      ORDER BY   b.order_id DESC))
 26   WHERE   stt > 5 AND stt <= 6
 27  /

Execution Plan
----------------------------------------------------------
Plan hash value: 1163929594
---------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name                      | Rows  |Bytes | Cost (%CPU)|Time     |
---------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |                           |    25 |67550 |    21   (5)|00:00:01 |
|*  1 |  VIEW                             |                           |    25 |67550 |    21   (5)|00:00:01 |
|   2 |   COUNT                           |                           |       |
|   3 |    VIEW                           |                           |    25 |67225 |    21   (5)|00:00:01 |
|   4 |     SORT ORDER BY                 |                           |    25 |11400 |    21   (5)|00:00:01 |
|   5 |      NESTED LOOPS                 |                           |       |
|   6 |       NESTED LOOPS                |                           |    25 |11400 |    20   (0)|00:00:01 |
|   7 |        TABLE ACCESS BY INDEX ROWID| NEWS_RELATION             |    25 |425 	 |     5   (0)|00:00:01 |
|*  8 |         INDEX RANGE SCAN          | IDX_CATEGORY_SHOWHOMEPAGE |    25 |
      |     3   (0)|00:00:01 |
|*  9 |        INDEX UNIQUE SCAN          | NEWS_CONTENT_PK           |     1 |		 |     0   (0)|00:00:01 |
|* 10 |       TABLE ACCESS BY INDEX ROWID | NEWS_CONTENT              |     1 |439   |     1   (0)|00:00:01 |

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

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("STT"<=6 AND "STT">5)
   8 - access("B"."CATEGORY_ID"=6282 AND "B"."SHOW_HOMEPAGE"=1)
   9 - access("B"."ICT_ID"="A"."ID")
  10 - filter("A"."END_TIME">SYSDATE@! AND ("STATE"=0 OR "STATE"=1) AND "A"."BEG
IN_TIME"<SYSDATE@!)

You see, no problem for the explain plan.

However, when I tracing a application from java (jdbc connection to my Oracle Database), I saw:

1- Finding the top SQL
system@dbwap>@sqltext
Enter value for SQL_ID: f6ztx90q72hnf

Session finding: 
no rows selected

SQL_TEXT                     SQL_ID        EXECUTIONS PARSE_CALLS  ELAP_EXEC
---------------------------- ------------- ---------- ----------- ----------
select * from (select rownum f6ztx90q72hnf       4779        4779 3547.09275
 stt,id,subject,title,imgpat
h,imgdetail,align,tgian from
 (Select id,subject,title,im
gpath,imgdetail,align,to_cha
r(public_time,:"SYS_B_0") tg
ian  from my_wap.news_CONTEN
T A,my_wap.news_RELATION B w
here A.BEGIN_TIME<SYSDATE an
d SYSDATE<A.END_TIME  and B.
Show_homepage=:"SYS_B_1" and
 (state=:"SYS_B_2" or state=
:"SYS_B_3") and B.category_i
d=:"SYS_B_4" and B.ICT_ID=A.
ID order by B.ORDER_ID desc)
) where stt>:"SYS_B_5" and s
tt<=:"SYS_B_6"

...

40 rows selected.

PROGRAM_ID PROGRAM_LINE#
---------- -------------
         0             0

Enter value for sql_id: f6ztx90q72hnf

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID f6ztx90q72hnf
--------------------
select * from (select rownum stt,id,subject,title,imgpath,imgdetail,alig
n,tgian from (Select id,subject,title,imgpath,imgdetail,align,to_char(pu
blic_time,:"SYS_B_0") tgian  from my_wap.news_CONTENT
A,my_wap.news_RELATION B where A.BEGIN_TIME<SYSDATE and
SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" and
(state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and
B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and
stt<=:"SYS_B_6"

Plan hash value: 411007010

------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name            | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                 |       |       |   102 (100)|          |
|   1 |  FILTER                            |                 |       |       |            |          |
|   2 |   VIEW                             |                 |   147 |   391K|   102   (1)| 00:00:02 |
|   3 |    COUNT                           |                 |       |       |            |          |
|   4 |     VIEW                           |                 |   147 |   390K|   102   (1)| 00:00:02 |
|   5 |      SORT ORDER BY                 |                 |   147 | 67032 |   102   (1)| 00:00:02 |
|   6 |       NESTED LOOPS                 |                 |       |       |            |          |
|   7 |        NESTED LOOPS                |                 |   147 | 67032 |   101   (0)| 00:00:02 |
|   8 |         TABLE ACCESS BY INDEX ROWID| NEWS_RELATION   |   147 |  2499 |    14   (0)| 00:00:01 |
|   9 |          INDEX RANGE SCAN          | CATEGORY_INDEX1 |   147 |       |     3   (0)| 00:00:01 |
|  10 |         INDEX UNIQUE SCAN          | NEWS_CONTENT_PK |     1 |       |     0   (0)|          |
|  11 |        TABLE ACCESS BY INDEX ROWID | NEWS_CONTENT    |     1 |   439 |     1   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------

SQL_ID f6ztx90q72hnf
--------------------
select * from (select rownum stt,id,subject,title,imgpath,imgdetail,alig
n,tgian from (Select id,subject,title,imgpath,imgdetail,align,to_char(pu
blic_time,:"SYS_B_0") tgian  from my_wap.news_CONTENT
A,my_wap.news_RELATION B where A.BEGIN_TIME<SYSDATE and
SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" and
(state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and
B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and
stt<=:"SYS_B_6"

Plan hash value: 1191708873

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name                      | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                           |       |       |   102 (100)|          |
|   1 |  FILTER                            |                           |       |       |            |          |
|   2 |   VIEW                             |                           |   147 |   391K|   102   (1)| 00:00:02 |
|   3 |    COUNT                           |                           |       |       |            |          |
|   4 |     VIEW                           |                           |   147 |   390K|   102   (1)| 00:00:02 |
|   5 |      SORT ORDER BY                 |                           |   147 | 67032 |   102   (1)| 00:00:02 |
|   6 |       NESTED LOOPS                 |                           |       |       |            |          |
|   7 |        NESTED LOOPS                |                           |   147 | 67032 |   101   (0)| 00:00:02 |
|   8 |         TABLE ACCESS BY INDEX ROWID| NEWS_RELATION             |   147 |  2499 |    14   (0)| 00:00:01 |
|   9 |          INDEX RANGE SCAN          | IDX_CATEGORY_SHOWHOMEPAGE |   147 |       |     3   (0)| 00:00:01 |
|  10 |         INDEX UNIQUE SCAN          | NEWS_CONTENT_PK           |     1 |       |     0   (0)|          |
|  11 |        TABLE ACCESS BY INDEX ROWID | NEWS_CONTENT              |     1 |   439 |     1   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------------------

SQL_ID f6ztx90q72hnf
--------------------
select * from (select rownum stt,id,subject,title,imgpath,imgdetail,alig
n,tgian from (Select id,subject,title,imgpath,imgdetail,align,to_char(pu
blic_time,:"SYS_B_0") tgian  from my_wap.news_CONTENT
A,my_wap.news_RELATION B where A.BEGIN_TIME<SYSDATE and
SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" and
(state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and
B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and
stt<=:"SYS_B_6"

Plan hash value: 3719282556

-------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name            | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |                 |       |       |       | 11726 (100)|          |
|   1 |  FILTER                           |                 |       |       |       |            |          |
|   2 |   VIEW                            |                 | 16591 |    43M|       | 11726   (1)| 00:02:21 |
|   3 |    COUNT                          |                 |       |       |       |            |          |
|   4 |     VIEW                          |                 | 16591 |    42M|       | 11726   (1)| 00:02:21 |
|   5 |      SORT ORDER BY                |                 | 16591 |  7388K|  7816K| 11726   (1)| 00:02:21 |
|   6 |       NESTED LOOPS                |                 |       |       |       |            |          |
|   7 |        NESTED LOOPS               |                 | 16591 |  7388K|       | 10119   (1)| 00:02:02 |
|   8 |         TABLE ACCESS FULL         | NEWS_RELATION   | 16591 |   275K|       |   245   (3)| 00:00:03 |
|   9 |         INDEX UNIQUE SCAN         | NEWS_CONTENT_PK |     1 |       |       |     0   (0)|          |
|  10 |        TABLE ACCESS BY INDEX ROWID| NEWS_CONTENT    |     1 |   439 |       |     1   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------------

SQL_ID f6ztx90q72hnf
--------------------
select * from (select rownum stt,id,subject,title,imgpath,imgdetail,alig
n,tgian from (Select id,subject,title,imgpath,imgdetail,align,to_char(pu
blic_time,:"SYS_B_0") tgian  from my_wap.news_CONTENT
A,my_wap.news_RELATION B where A.BEGIN_TIME<SYSDATE and
SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" and
(state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and
B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and
stt<=:"SYS_B_6"

Plan hash value: 4010925109

-------------------------------------------------------------------------------------------------
| Id  | Operation               | Name          | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |               |       |       |       | 19472 (100)|          |
|   1 |  FILTER                 |               |       |       |       |            |          |
|   2 |   VIEW                  |               | 41257 |   107M|       | 19472   (1)| 00:03:54 |
|   3 |    COUNT                |               |       |       |       |            |          |
|   4 |     VIEW                |               | 41257 |   110M|       | 19472   (1)| 00:03:54 |
|   5 |      SORT ORDER BY      |               | 41257 |    17M|    18M| 19472   (1)| 00:03:54 |
|   6 |       HASH JOIN         |               | 41257 |    17M|       | 15475   (1)| 00:03:10 |
|   7 |        TABLE ACCESS FULL| NEWS_RELATION | 41258 |   684K|       |   245   (3)| 00:00:03 |
|   8 |        TABLE ACCESS FULL| NEWS_CONTENT  | 40981 |    17M|       | 15229   (1)| 00:03:03 |
-------------------------------------------------------------------------------------------------


116 rows selected.


What's happend to this SQL?
- The different plan_hash
- Mistake Index usage from the second execution time
- Do much I/O on FTS

Re: Lost Index from the second execution time [message #589913 is a reply to message #589912] Thu, 11 July 2013 23:08 Go to previous messageGo to next message
trantuananh24hg
Messages: 619
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Please, keep a keen on eye to my tkprof file using dbms_monitor.session_trace_enable(Application_ID):

SQL ID: f6ztx90q72hnf
Plan Hash: 4010925069
select * 
from
 (select rownum stt,id,subject,title,imgpath,imgdetail,align,tgian from 
  (Select id,subject,title,imgpath,imgdetail,align,to_char(public_time,
  :"SYS_B_0") tgian  from my_wap.news_CONTENT A,my_wap.news_RELATION B where 
  A.BEGIN_TIME<SYSDATE and SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" 
  and (state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and 
  B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and stt<=
  :"SYS_B_6"


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.01       0.00          0          0          0           0
Execute      5      0.00       0.00          0          0          0           0
Fetch       10      1.12       1.14          0     286625          0          50
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       20      1.13       1.14          0     286625          0          50

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 88  

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  FILTER  (cr=57325 pr=0 pw=0 time=36 us)
     10   VIEW  (cr=57325 pr=0 pw=0 time=27 us cost=19528 size=114204090 card=41833)
  12551    COUNT  (cr=57325 pr=0 pw=0 time=52481 us)
  12551     VIEW  (cr=57325 pr=0 pw=0 time=33593 us cost=19528 size=113660261 card=41833)
  12551      SORT ORDER BY (cr=57325 pr=0 pw=0 time=15338 us cost=19528 size=19075848 card=41833)
  12551       HASH JOIN  (cr=57325 pr=0 pw=0 time=103188 us cost=15476 size=19075848 card=41833)
  42108        TABLE ACCESS FULL NEWS_RELATION (cr=883 pr=0 pw=0 time=40187 us cost=246 size=711178 card=41834)
  43662        TABLE ACCESS FULL NEWS_CONTENT (cr=56442 pr=0 pw=0 time=126770 us cost=15229 size=18687352 card=42568)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      15        0.00          0.00
  SQL*Net message from client                    15       11.08         22.49
  SQL*Net more data to client                    10        0.00          0.00
********************************************************************************

SQL ID: f6ztx90q72hnf
Plan Hash: 411007006
select * 
from
 (select rownum stt,id,subject,title,imgpath,imgdetail,align,tgian from 
  (Select id,subject,title,imgpath,imgdetail,align,to_char(public_time,
  :"SYS_B_0") tgian  from my_wap.news_CONTENT A,my_wap.news_RELATION B where 
  A.BEGIN_TIME<SYSDATE and SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" 
  and (state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and 
  B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and stt<=
  :"SYS_B_6"


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        3      0.00       0.00          0          0          0           0
Execute      3      0.00       0.00          0          0          0           0
Fetch        6      0.07       0.06          0       7476          0          30
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       12      0.07       0.06          0       7476          0          30

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 88  

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  FILTER  (cr=2492 pr=0 pw=0 time=45 us)
     10   VIEW  (cr=2492 pr=0 pw=0 time=27 us cost=1743 size=6046950 card=2215)
    114    COUNT  (cr=2492 pr=0 pw=0 time=452 us)
    114     VIEW  (cr=2492 pr=0 pw=0 time=339 us cost=1743 size=6018155 card=2215)
    114      SORT ORDER BY (cr=2492 pr=0 pw=0 time=113 us cost=1743 size=1010040 card=2215)
    114       NESTED LOOPS  (cr=2492 pr=0 pw=0 time=12430 us)
    844        NESTED LOOPS  (cr=1690 pr=0 pw=0 time=7105 us cost=1527 size=1010040 card=2215)
   2507         TABLE ACCESS BY INDEX ROWID NEWS_RELATION (cr=609 pr=0 pw=0 time=4761 us cost=161 size=37655 card=2215)
   2514          INDEX RANGE SCAN CATEGORY_INDEX1 (cr=10 pr=0 pw=0 time=2889 us cost=8 size=0 card=2223)(object id 74736)
    844         INDEX UNIQUE SCAN NEWS_CONTENT_PK (cr=1081 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 146957)
    114        TABLE ACCESS BY INDEX ROWID NEWS_CONTENT (cr=802 pr=0 pw=0 time=0 us cost=1 size=439 card=1)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       9        0.00          0.00
  SQL*Net message from client                     9        2.56          5.01
  SQL*Net more data to client                     6        0.00          0.00
********************************************************************************

SQL ID: f6ztx90q72hnf
Plan Hash: 3719282556
select * 
from
 (select rownum stt,id,subject,title,imgpath,imgdetail,align,tgian from 
  (Select id,subject,title,imgpath,imgdetail,align,to_char(public_time,
  :"SYS_B_0") tgian  from my_wap.news_CONTENT A,my_wap.news_RELATION B where 
  A.BEGIN_TIME<SYSDATE and SYSDATE<A.END_TIME  and B.Show_homepage=:"SYS_B_1" 
  and (state=:"SYS_B_2" or state=:"SYS_B_3") and B.category_id=:"SYS_B_4" and 
  B.ICT_ID=A.ID order by B.ORDER_ID desc)) where stt>:"SYS_B_5" and stt<=
  :"SYS_B_6"


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse       22      0.03       0.00          0          0          0           0
Execute     22      0.03       0.02          0          0          0           0
Fetch       44      4.58       4.56          0     430081          0         220
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       88      4.64       4.59          0     430081          0         220

Misses in library cache during parse: 7
Optimizer mode: ALL_ROWS
Parsing user id: 88  

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  FILTER  (cr=23451 pr=0 pw=0 time=36 us)
     10   VIEW  (cr=23451 pr=0 pw=0 time=18 us cost=15279 size=57504720 card=21064)
   7659    COUNT  (cr=23451 pr=0 pw=0 time=33822 us)
   7659     VIEW  (cr=23451 pr=0 pw=0 time=21314 us cost=15279 size=57230888 card=21064)
   7659      SORT ORDER BY (cr=23451 pr=0 pw=0 time=10083 us cost=15279 size=9605184 card=21064)
   7659       NESTED LOOPS  (cr=23451 pr=0 pw=0 time=125208 us)
  13475        NESTED LOOPS  (cr=10422 pr=0 pw=0 time=97114 us cost=13236 size=9605184 card=21064)
  20032         TABLE ACCESS FULL NEWS_RELATION (cr=883 pr=0 pw=0 time=28834 us cost=245 size=358088 card=21064)
  13475         INDEX UNIQUE SCAN NEWS_CONTENT_PK (cr=9539 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 146957)
   7659        TABLE ACCESS BY INDEX ROWID NEWS_CONTENT (cr=13029 pr=0 pw=0 time=0 us cost=1 size=439 card=1)


So, may you explain to me? And why or how I avoid the problem?

Thank you very much!
Re: Lost Index from the second execution time [message #591391 is a reply to message #589912] Sun, 28 July 2013 02:33 Go to previous messageGo to next message
Lalit Kumar B
Messages: 2547
Registered: May 2013
Location: World Wide on the Web
Senior Member
trantuananh24hg wrote on Fri, 12 July 2013 09:34
What's happend to this SQL?
- The different plan_hash
- Mistake Index usage from the second execution time
- Do much I/O on FTS


The different plan_hash_value for the same sql_id could be due to many factors:-

1. Adaptive cursor sharing - If there are bind variables.
2. You upgraded your DB version recently.
3. Optimizer hints were used to check execution plan with previous DB version. For example:- optimzer_features_enables
4. Skewness of the data over a period of time
etc.

There are 2 execution plans in your case, one is good, another is bad. You need to make sure that the SQL uses the good execution plan. This could be achieved by many ways. Using appropriate hints, pinning the execution plan, using SQL Plan Baselines, using optimizer hints(if it's a version issue) etc.
Re: Lost Index from the second execution time [message #591586 is a reply to message #591391] Mon, 29 July 2013 21:21 Go to previous messageGo to next message
trantuananh24hg
Messages: 619
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Thank you for your reply.

Lalit Kumar B wrote on Sun, 28 July 2013 07:33

The different plan_hash_value for the same sql_id could be due to many factors:-

1. Adaptive cursor sharing - If there are bind variables.


My cursor sharing parameter is SIMILAR, yes, the array code in Application was not using bind variable, instead of, it used litteral string.

Quote:

2. You upgraded your DB version recently.
3. Optimizer hints were used to check execution plan with previous DB version. For example:- optimzer_features_enables


My Oracle Database was created as new Database 11gr2, it've not been being upgrade any patch still now.

Quote:

4. Skewness of the data over a period of time
etc.


I've checked many thing in my Database before I posted here.

Quote:

There are 2 execution plans in your case, one is good, another is bad. You need to make sure that the SQL uses the good execution plan. This could be achieved by many ways. Using appropriate hints, pinning the execution plan, using SQL Plan Baselines, using optimizer hints(if it's a version issue) etc.


Of coure, I must make the SQL uses the good execution plan, not bad one. No hint is to be used along to my hint in application's code, no baselines is to be used along to my created baselines, ...

This is the problem as "hot-block" in my Database, as below, you will see the table NEWS_CONTENT was retrieved many block, physical block. This is the problem in Application, not in Database. I wrote a procedure call my SQL_ID into 1000 time continous, but the good SQL execution plan was used, not bad. I wrote a java call into 500 time continous, using the litteral string, the bad execution plan was choosed, not good. This is the question I wonder still now.

Thank you!
Re: Lost Index from the second execution time [message #591655 is a reply to message #591586] Tue, 30 July 2013 10:05 Go to previous messageGo to next message
Lalit Kumar B
Messages: 2547
Registered: May 2013
Location: World Wide on the Web
Senior Member
trantuananh24hg wrote on Tue, 30 July 2013 07:51

This is the problem as "hot-block" in my Database, as below, you will see the table NEWS_CONTENT was retrieved many block, physical block. This is the problem in Application, not in Database.


I could not understand the two contradictory statements. could you please elucidate on your requirement.

What I understand is just that when you execute the SQL from Java as a dynamic SQL the CBO is using the bad execution plan.
Re: Lost Index from the second execution time [message #591682 is a reply to message #591655] Tue, 30 July 2013 21:24 Go to previous message
trantuananh24hg
Messages: 619
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Lalit Kumar B wrote on Tue, 30 July 2013 15:05


I could not understand the two contradictory statements. could you please elucidate on your requirement.

What I understand is just that when you execute the SQL from Java as a dynamic SQL the CBO is using the bad execution plan.


Thank you for your reply!

I assume the hot block problem caused missing index among many executions does at one. (Well, as my understand, there're 6 reasons cause missing index)

Exec 1: Using the good plan
Exec 2: Using the good plan
...
Exec m: Using the good plan for one, bad plan for twice
Exec m+1: Using the bad plan

Will it appear? Oracle never make mistake, then I though, CBO is right, but why did it not use the index in this case?

In my addmrpt:
Quote:

Rationale
Database time for this SQL was divided as follows: 100% for SQL
execution, 0% for parsing, 0% for PL/SQL execution and 0% for Java
execution.
Rationale
SQL statement with SQL_ID "f6ztx90q72hnf" was executed 3829 times and
had an average elapsed time of 0.23 seconds.
Rationale
At least 4 distinct execution plans were utilized for this SQL statement
during the analysis period.
Rationale
I/O and Cluster wait for TABLE "MY_WAP.NEWS_CONTENT" with object ID
93564 consumed 62% of the database time spent on this SQL statement


Now, I wrote the PL/SQL loop 200 times to do in my Database, no-one-execution-plan choose bad.

system@wap>@sqldef
...
PROGRAM_ID PROGRAM_LINE#
---------- -------------
      5621           221
         
77 rows selected.


tkprof:
SELECT   *
        FROM   (SELECT   ROWNUM stt,
                     id,
                     subject,
                     title,
                     imgpath,
                     imgdetail,
                     align,
                     tgian
              FROM   (  SELECT   id,
                                 subject,
                                 title,
                                 imgpath,
                                 imgdetail,
                                 align,
                                 TO_CHAR (public_time, 'dd-mm-yyyy hh24:mi:ss') tgian
                          FROM   adwap.news_content a, adwap.news_relation b
                         WHERE       a.begin_time < SYSDATE
                                 AND SYSDATE < a.end_time
                                 AND b.show_homepage = :1
                                 AND (state = :2 or state = :3)
                                 AND b.category_id = :4
                                 AND b.ict_id = a.id
                      ORDER BY   b.order_id DESC))
   WHERE   stt > 10 AND stt <= 20

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute    200      0.04       0.03          0          0          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      201      0.04       0.04          0          0          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 93     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  VIEW  (cr=0 pr=0 pw=0 time=0 us cost=6 size=2702 card=1)
      0   COUNT  (cr=0 pr=0 pw=0 time=0 us)
      0    VIEW  (cr=0 pr=0 pw=0 time=0 us cost=6 size=2689 card=1)
      0     SORT ORDER BY (cr=0 pr=0 pw=0 time=0 us cost=6 size=467 card=1)
      0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us)
      0       NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=5 size=467 card=1)
      0        TABLE ACCESS BY INDEX ROWID NEWS_RELATION (cr=0 pr=0 pw=0 time=0 us cost=4 size=17 card=1)
      0         INDEX RANGE SCAN IDX_CATEGORY_SHOWHOMEPAGE (cr=0 pr=0 pw=0 time=0 us cost=3 size=0 card=1)(object id 165911)
      0        INDEX UNIQUE SCAN NEWS_CONTENT_PK (cr=0 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 165909)
      0       TABLE ACCESS BY INDEX ROWID NEWS_CONTENT (cr=0 pr=0 pw=0 time=0 us cost=1 size=450 card=1)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net break/reset to client                   2        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00

But it was the bad execution plan when I trace it from java using litteral string

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 4010925069
------------------------------------------------------------------------------------------------
| Id  | Operation               | Name          | Rows  | Bytes |TempSpc| Cost(%CPU)| Time     |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |               |       |       |       | 19472(100)|          |
|   1 |  FILTER                 |               |       |       |       |			|          |
|   2 |   VIEW                  |               | 41257 |   107M|       | 19472(1)	| 00:03:54 |
|   3 |    COUNT                |               |       |       |       |			|          |
|   4 |     VIEW                |               | 41257 |   106M|       | 19472(1)	| 00:03:54 |
|   5 |      SORT ORDER BY      |               | 41257 |    17M|    18M| 19472(1)	| 00:03:54 |
|   6 |       HASH JOIN         |               | 41257 |    17M|       | 15475(1)	| 00:03:06 |
|   7 |        TABLE ACCESS FULL| NEWS_RELATION | 41258 |   684K|       |   245(3)	| 00:00:03 |
|   8 |        TABLE ACCESS FULL| NEWS_CONTENT  | 40981 |    17M|       | 15229(1)	| 00:03:03 |
------------------------------------------------------------------------------------------------


116 rows selected.

-- Press any key to define which object associated

Enter value for objid: 0

no rows selected		


I've not tested for execution >1000 time to measure I/O from PL/SQL, am I wrong when I assume the more execution impacts to block till what threshold one, the index will not to be used?

[Updated on: Tue, 30 July 2013 23:36]

Report message to a moderator

Previous Topic: How to determine memory usage for a function
Next Topic: Performance tunning
Goto Forum:
  


Current Time: Mon Dec 29 07:55:44 CST 2014

Total time taken to generate the page: 0.07865 seconds