Oracle Database Blog: Experiments & Learnings

July 22, 2011

Stored Outlines Weird Behaviour

Filed under: Oracle RDBMS — Tags: , — Saurabh Manroy @ 7:42 pm

Similar to my last post, to fix an execution plan of a query, I decided to create stored outlines. It was a two node RAC environment running 10.2.0.4 RDBMS software. On one of the nodes, query was consuming lots of CPU.

SQL_ID 8pg71n7580t88

Plan with Good response time

Plan hash value: 1087074870
----------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                              | Name              | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                       |                   |       |       |   355 (100)|          |       |       |
|   1 |  SORT ORDER BY                         |                   |     2 |   248 |   355   (1)| 00:00:05 |       |       |
|   2 |   CONCATENATION                        |                   |       |       |            |          |       |       |
|   3 |    FILTER                              |                   |       |       |            |          |       |       |
|   4 |     HASH JOIN SEMI                     |                   |     1 |   124 |   186   (1)| 00:00:03 |       |       |
|   5 |      PARTITION RANGE ITERATOR          |                   |     8 |   720 |   179   (0)| 00:00:03 |   KEY |   KEY |
|   6 |       TABLE ACCESS BY LOCAL INDEX ROWID| xxxxxxx           |     8 |   720 |   179   (0)| 00:00:03 |   KEY |   KEY |
|   7 |        INDEX RANGE SCAN                | INX_xxxxxxx_ACCT  |   168 |       |   127   (0)| 00:00:02 |   KEY |   KEY |
|   8 |      TABLE ACCESS BY GLOBAL INDEX ROWID| YYYY              |     3 |   102 |     6   (0)| 00:00:01 | ROW L | ROW L |
|   9 |       INDEX RANGE SCAN                 | IND_YYYY_ACCTBILL |     3 |       |     3   (0)| 00:00:01 |       |       |
|  10 |    FILTER                              |                   |       |       |            |          |       |       |
|  11 |     NESTED LOOPS SEMI                  |                   |     1 |   124 |   168   (0)| 00:00:03 |       |       |
|  12 |      PARTITION RANGE ITERATOR          |                   |     1 |    90 |   167   (0)| 00:00:03 |   KEY |   KEY |
|  13 |       TABLE ACCESS BY LOCAL INDEX ROWID| xxxxxxx           |     1 |    90 |   167   (0)| 00:00:03 |   KEY |   KEY |
|  14 |        INDEX RANGE SCAN                | INX_xxxxxxx_SUBS  |   122 |       |   127   (0)| 00:00:02 |   KEY |   KEY |
|  15 |      PARTITION RANGE ITERATOR          |                   |     3 |   102 |     1   (0)| 00:00:01 |   KEY |   KEY |
|  16 |       INDEX UNIQUE SCAN                | PK_YYYY           |     3 |   102 |     1   (0)| 00:00:01 |   KEY |   KEY |
----------------------------------------------------------------------------------------------------------------------------

Plan with Bad response time

Plan hash value: 3132269520
----------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                              | Name              | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                       |                   |       |       |   352 (100)|          |       |       |
|   1 |  SORT ORDER BY                         |                   |     2 |   248 |   352   (1)| 00:00:05 |       |       |
|   2 |   CONCATENATION                        |                   |       |       |            |          |       |       |
|*  3 |    FILTER                              |                   |       |       |            |          |       |       |
|*  4 |     HASH JOIN SEMI                     |                   |     1 |   124 |   179   (1)| 00:00:03 |       |       |
|   5 |      PARTITION RANGE ITERATOR          |                   |    12 |  1080 |   175   (0)| 00:00:03 |   KEY |   KEY |
|*  6 |       TABLE ACCESS BY LOCAL INDEX ROWID| xxxxxxx           |    12 |  1080 |   175   (0)| 00:00:03 |   KEY |   KEY |
|*  7 |        INDEX RANGE SCAN                | INX_xxxxxxx_ACCT  |   159 |       |   127   (0)| 00:00:02 |   KEY |   KEY |
|   8 |      PARTITION RANGE ITERATOR          |                   |     1 |    34 |     3   (0)| 00:00:01 |   KEY |   KEY |
|*  9 |       INDEX RANGE SCAN                 | PK_YYYY           |     1 |    34 |     3   (0)| 00:00:01 |   KEY |   KEY |
|* 10 |    FILTER                              |                   |       |       |            |          |       |       |
|  11 |     NESTED LOOPS SEMI                  |                   |     1 |   124 |   172   (0)| 00:00:03 |       |       |
|  12 |      PARTITION RANGE ITERATOR          |                   |     1 |    90 |   171   (0)| 00:00:03 |   KEY |   KEY |
|* 13 |       TABLE ACCESS BY LOCAL INDEX ROWID| xxxxxxx           |     1 |    90 |   171   (0)| 00:00:03 |   KEY |   KEY |
|* 14 |        INDEX RANGE SCAN                | INX_xxxxxxx_SUBS  |   137 |       |   127   (0)| 00:00:02 |   KEY |   KEY |
|  15 |      PARTITION RANGE ITERATOR          |                   |     1 |    34 |     1   (0)| 00:00:01 |   KEY |   KEY |
|* 16 |       INDEX UNIQUE SCAN                | PK_YYYY           |     1 |    34 |     1   (0)| 00:00:01 |   KEY |   KEY |
----------------------------------------------------------------------------------------------------------------------------

Stored Outline was created from the node on which query was running supposedly Good Plan.

SQL>select outline_sid,hash_value,plan_hash_value,child_number from v$sql where sql_id='8pg71n7580t88';
OUTLINE_SID HASH_VALUE PLAN_HASH_VALUE CHILD_NUMBER
----------- ---------- --------------- ------------
3397412104      1087074870            2
SQL>alter session set create_stored_outlines=true;
Session altered.
SQL>exec dbms_outln.create_outline(3397412104,2);
PL/SQL procedure successfully completed.
SQL>select * from dba_outlines;
NAME                           OWNER                          CATEGORY                       USED   TIMESTAMP
------------------------------ ------------------------------ ------------------------------ ------ --------------
VERSION
----------------------------------------------------------------
SQL_TEXT                                                                         SIGNATURE
-------------------------------------------------------------------------------- --------------------------------
COMPATIBLE   ENABLED  FORMAT
------------ -------- ------
SYS_OUTLINE_11051118530725015  ACCT                           DEFAULT                        UNUSED 20110511185307
10.2.0.4.0
select  to_char(b.AcctId),b.YYYYCycle,b.YYYYNum,to_char(b.SubsId),b.ItemType,b.I 5266676E85773042383790483873E4FB
COMPATIBLE   ENABLED  NORMAL

Shared pool was flushed on the problematic node and I waited for fresh execution plan to be loaded into shared pool. Here is what I got:

SQL>select * from table (dbms_xplan.display_cursor('8pg71n7580t88'));
PLAN_TABLE_OUTPUT
SQL_ID  8pg71n7580t88, child number 0
-------------------------------------
Plan hash value: 3132269520
----------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                              | Name              | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
----------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                       |                   |       |       |   353 (100)|          |       |       |
|   1 |  SORT ORDER BY                         |                   |     2 |   248 |   353   (1)| 00:00:05 |       |       |
|   2 |   CONCATENATION                        |                   |       |       |            |          |       |       |
|*  3 |    FILTER                              |                   |       |       |            |          |       |       |
|*  4 |     HASH JOIN SEMI                     |                   |     1 |   124 |   179   (1)| 00:00:03 |       |       |
|   5 |      PARTITION RANGE ITERATOR          |                   |    14 |  1260 |   175   (0)| 00:00:03 |   KEY |   KEY |
|*  6 |       TABLE ACCESS BY LOCAL INDEX ROWID| xxxxxxx           |    14 |  1260 |   175   (0)| 00:00:03 |   KEY |   KEY |
|*  7 |        INDEX RANGE SCAN                | INX_xxxxxxx_ACCT  |   159 |       |   127   (0)| 00:00:02 |   KEY |   KEY |
|   8 |      PARTITION RANGE ITERATOR          |                   |     1 |    34 |     3   (0)| 00:00:01 |   KEY |   KEY |
|*  9 |       INDEX RANGE SCAN                 | PK_YYYY           |     1 |    34 |     3   (0)| 00:00:01 |   KEY |   KEY |
|* 10 |    FILTER                              |                   |       |       |            |          |       |       |
|  11 |     NESTED LOOPS SEMI                  |                   |     1 |   124 |   173   (0)| 00:00:03 |       |       |
|  12 |      PARTITION RANGE ITERATOR          |                   |     1 |    90 |   172   (0)| 00:00:03 |   KEY |   KEY |
|* 13 |       TABLE ACCESS BY LOCAL INDEX ROWID| xxxxxxx           |     1 |    90 |   172   (0)| 00:00:03 |   KEY |   KEY |
|* 14 |        INDEX RANGE SCAN                | INX_xxxxxxx_SUBS  |   140 |       |   127   (0)| 00:00:02 |   KEY |   KEY |
|  15 |      PARTITION RANGE ITERATOR          |                   |     1 |    34 |     1   (0)| 00:00:01 |   KEY |   KEY |
|* 16 |       INDEX UNIQUE SCAN                | PK_YYYY           |     1 |    34 |     1   (0)| 00:00:01 |   KEY |   KEY |
----------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
-- removed because of customer's data
Note
-----
- outline "SYS_OUTLINE_11051118530725015" used for this statement

So, outline was used but with BAD plan ?  I raised an SR for this problem and after weeks of investigation, it came out to be an Oracle Bug 6455659 which affects multibyte characterset. Customer’s database was having UTF8 characterset.

This bug affects 10.2.0.4 and 11.1.0.6 RDBMS versions. One-off patch is available for some platforms.  There is no workaround available. This bug is fixed in 10.2.0.5 and 11.1.0.7 versions.

In my next post I’ll explain how I fixed the problem of this slow running query.

Advertisements

1 Comment »

  1. […] my last  post, I demonstrated how stored outlines ditched me. Then I started looking out for other options […]

    Pingback by Other Options ! « Oracle Database Blog: Experiments & Learnings — July 26, 2011 @ 9:57 am


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Blog at WordPress.com.

%d bloggers like this: