HASH GROUP BY not used when using more that 354 aggregate functions

Few days ago we had performance problem with one of our main application views. This was complex view that used a lot of aggregate function. Functions were used to transpose rows into columns.

When developer added few more aggregate functions for a new columns, query performance changed significantly and we had performance problem.

After quick analysis I have noticed one change in the execution plan.

HASH GROUP BY aggregation was replaced with less performant SORT GROUP BY. I have tried to force HASH GROUP BY using hints but nothing helped.


We tried to reproduce problem using dummy tables and then colleague found what was triggering plan change.

In this example I have query with 354 unique aggregate functions which is using HASH GROUP BY.

SELECT
          *
      FROM (SELECT LEVEL ID
             FROM DUAL CONNECT BY LEVEL < 1000) VANJSKI,
          (  SELECT
                    123 UNUTARNJI_ID,
                     sum(1) kolona0,
                     sum(1) kolona1,
                     sum(2) kolona2,
...
...
...
                     sum(350) kolona350    ,
                     sum(351) kolona351    ,
                     sum(352) kolona352    ,
                     sum(353) kolona353    ,
                     sum(354) kolona354
               FROM DUAL
           GROUP BY 123) UNUTARNJI
    WHERE     VANJSKI.ID = UNUTARNJI.UNUTARNJI_ID(+);

Plan hash value: 2294628051
---------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| A-Rows |   A-Time   |  OMem |  1Mem | Used-Mem |
---------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |      |      1 |        |       |     5 (100)|    999 |00:00:00.01 |       |       |          |
|*  1 |  HASH JOIN OUTER               |      |      1 |      1 |  4631 |     5  (20)|    999 |00:00:00.01 |  2293K|  2293K| 1549K (0)|
|   2 |   VIEW                         |      |      1 |      1 |    13 |     2   (0)|    999 |00:00:00.01 |       |       |          |
|   3 |    CONNECT BY WITHOUT FILTERING|      |      1 |        |       |            |    999 |00:00:00.01 |       |       |          |
|   4 |     FAST DUAL                  |      |      1 |      1 |       |     2   (0)|      1 |00:00:00.01 |       |       |          |
|   5 |   VIEW                         |      |      1 |      1 |  4618 |     2   (0)|      1 |00:00:00.01 |       |       |          |
|   6 |    HASH GROUP BY               |      |      1 |      1 |       |     2   (0)|      1 |00:00:00.01 |   677K|   677K|  723K (0)|
|   7 |     FAST DUAL                  |      |      1 |      1 |       |     2   (0)|      1 |00:00:00.01 |       |       |          |
---------------------------------------------------------------------------------------------------------------------------------------

Notice what will happen if I change "sum(1) kolona0" function and add one more unique function.

SELECT
          *
      FROM (SELECT LEVEL ID
             FROM DUAL CONNECT BY LEVEL < 1000) VANJSKI,
          (  SELECT
                    123 UNUTARNJI_ID,
                     sum(355) kolona0,
                     sum(1) kolona1,
                     sum(2) kolona2,
...
...
...
                     sum(350) kolona350    ,
                     sum(351) kolona351    ,
                     sum(352) kolona352    ,
                     sum(353) kolona353    ,
                     sum(354) kolona354
               FROM DUAL
           GROUP BY 123) UNUTARNJI
    WHERE     VANJSKI.ID = UNUTARNJI.UNUTARNJI_ID(+);

Plan hash value: 2326946862
---------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| A-Rows |   A-Time   |  OMem |  1Mem | Used-Mem |
---------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |      |      1 |        |       |     5 (100)|    999 |00:00:00.01 |       |       |          |
|*  1 |  HASH JOIN OUTER               |      |      1 |      1 |  4631 |     5  (20)|    999 |00:00:00.01 |  2293K|  2293K| 1645K (0)|
|   2 |   VIEW                         |      |      1 |      1 |    13 |     2   (0)|    999 |00:00:00.01 |       |       |          |
|   3 |    CONNECT BY WITHOUT FILTERING|      |      1 |        |       |            |    999 |00:00:00.01 |       |       |          |
|   4 |     FAST DUAL                  |      |      1 |      1 |       |     2   (0)|      1 |00:00:00.01 |       |       |          |
|   5 |   VIEW                         |      |      1 |      1 |  4618 |     2   (0)|      1 |00:00:00.01 |       |       |          |
|   6 |    SORT GROUP BY               |      |      1 |      1 |       |     2   (0)|      1 |00:00:00.01 | 20480 | 20480 |18432  (0)|
|   7 |     FAST DUAL                  |      |      1 |      1 |       |     2   (0)|      1 |00:00:00.01 |       |       |          |
---------------------------------------------------------------------------------------------------------------------------------------

Query execution plan changed - HASH GROUP BY was replaced with SORT GROUP BY.


This was obviously limitation for HASH GROUP BY but I couldn't find more information using Oracle docs or Google so I have asked Oracle support for a confirmation.

From Oracle support I have received answer that similar case was bug closed as not bug, without workaround. Using default DB_BLOCK_SIZE, the limitation is set to 354 aggregate functions.

To solve performance problem we have changed view to avoid HASH GROUP BY limitation.

Testing environment - Oracle Database 12c Enterprise Edition Release 12.1.0.2.0

Read more →

Beware of intensive slow query logging when using - log_queries_not_using_indexes

MySQL slow query log is great for identifying slow queries that are good candidates for optimisation. Slow query logging is disabled by default, but it is activated by DBA's or developers on most environments.

You can use slow query log to record all the traffic but be careful with this action as logging all traffic could be very I/O intensive and could have negative impact on general performance. It is recommended to record all traffic only for specific time periods.

This is why slow query logging is controlled with long_query_time parameter to log only slow queries.
But there is another parameter to think about - log_queries_not_using_indexes.

By default log_queries_not_using_indexes is disabled. If you have this parameter turned on you will log queries that don’t use an index, or that perform a full index scan where the index doesn't limit the number of rows - regardless of time taken.

If you have long_query_time configured to reasonable time, and still notice that queries are intensively logged in slow query log file, then you probably have enabled log_queries_not_using_indexes.

Enabling this parameter you’re practically saying that full scans are "evil" and should be considered for optimisation. But full scan doesn’t always mean that query is slow. In some situations query optimizer chooses full table scan as better option than index or you are probably querying very small table.


For instance, on several occasions I've noticed slow query logs flooded with queries like this:

# Time: 171021 17:51:45
# User@Host: monitor[monitor] @ localhost []
# Thread_id: 1492974  Schema:   QC_hit: No
# Query_time: 0.000321  Lock_time: 0.000072  Rows_sent: 0  Rows_examined: 1
# Full_scan: Yes  Full_join: No  Tmp_table: Yes  Tmp_table_on_disk: No
# Filesort: No  Filesort_on_disk: No  Merge_passes: 0  Priority_queue: No
SET timestamp=1508608305;
SELECT
      SCHEMA_NAME
    FROM information_schema.schemata
    WHERE SCHEMA_NAME NOT IN ('mysql', 'performance_schema', 'information_schema');

+------+-------------+----------+------+---------------+------+---------+------+------+-------------+
| id   | select_type | table    | type | possible_keys | key  | key_len | ref  | rows | Extra       |
+------+-------------+----------+------+---------------+------+---------+------+------+-------------+
|    1 | SIMPLE      | schemata | ALL  | NULL          | NULL | NULL    | NULL | NULL | Using where |
+------+-------------+----------+------+---------------+------+---------+------+------+-------------+

Notice, Query_time: 0.000321.

Should I optimize query that is running 0.000321 secs with adding indexes. Probably not. But anyway, my log is flooded with this or similar queries.

I don’t see that parameter very useful and I would leave it on default value to avoid possible problems with intensive query logging.

Read more →

Using In-Memory Option with SQL Plan Baselines, SQL Profiles and SQL Hints

Oracle database In-Memory option was introduced in 12.1.0.2 patchset. It is great feature to improve performance of analytic queries. For mixed workload OLTP environments In-Memory option could improve performance of analytic queries without significant negative affect on quick OLTP queries or DML operations.

So you have decided that In-Memory option could be great for you and now you want to implement this option for your critical production database.

But in your code you have many SQL hints hard-coded, SQL Profiles implemented or SQL Plan baselines created to solve problems with unstable query performance. What will happen with execution plans if you populate In-Memory column store with critical tables in the database.

Example:
Version : Oracle 12.1.0.2

For test I will use query with fixed plan using both SQL profile and SQL plan baseline.

select object_type, count(*)
from admin.big_table
group by object_type;

OBJECT_TYPE               COUNT(*)
----------------------- ----------
PACKAGE                      14858
PACKAGE BODY                 13724
PROCEDURE                     2254
PROGRAM                        110


SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  8g28yt7c1nacr, child number 0
-------------------------------------
select object_type, count(*) from admin.big_table group by object_type

Plan hash value: 1753714399

--------------------------------------------------------------------------------
| Id  | Operation          | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |           |       |       |  4819 (100)|          |
|   1 |  HASH GROUP BY     |           |    39 |   351 |  4819   (1)| 00:00:01 |
|   2 |   TABLE ACCESS FULL| BIG_TABLE |  1000K|  8789K|  4795   (1)| 00:00:01 |
--------------------------------------------------------------------------------

DECLARE
my_plans pls_integer;
BEGIN
  my_plans := DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE(
    sql_id => '8g28yt7c1nacr');
END;
/

@coe_xfr_sql_profile 8g28yt7c1nacr 1753714399
@coe_xfr_sql_profile_8g28yt7c1nacr_1753714399.sql


select object_type, count(*)
from admin.big_table
group by object_type;


SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));


SQL_ID  8g28yt7c1nacr, child number 0
-------------------------------------
select object_type, count(*) from admin.big_table group by object_type

Plan hash value: 1753714399

--------------------------------------------------------------------------------
| Id  | Operation          | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |           |       |       |  4819 (100)|          |
|   1 |  HASH GROUP BY     |           |    39 |   351 |  4819   (1)| 00:00:01 |
|   2 |   TABLE ACCESS FULL| BIG_TABLE |  1000K|  8789K|  4795   (1)| 00:00:01 |
--------------------------------------------------------------------------------

Note
-----
   - SQL profile coe_8g28yt7c1nacr_1753714399 used for this statement
   - SQL plan baseline SQL_PLAN_1wn92bz7gqvxx73be0962 used for this statement

Note section in execution plan output says that I’m using both SQL profile and SQL plan baseline for this query.

I have previously enabled In-Memory Column Store and now I will populate table data into the in-memory column store.

alter table admin.big_table inmemory priority critical;

col segment_name for a15
select segment_name, 
       inmemory_size/1024/1024 im_size_mb,
       bytes/1024/1024 size_mb,
       bytes_not_populated,
       inmemory_compression
from v$im_segments;

SEGMENT_NAME    IM_SIZE_MB    SIZE_MB BYTES_NOT_POPULATED INMEMORY_COMPRESS
--------------- ---------- ---------- ------------------- -----------------
BIG_TABLE          27.1875        144                   0 FOR QUERY LOW

1 row selected.

Run query again.

select object_type, count(*)
from admin.big_table
group by object_type;

SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  8g28yt7c1nacr, child number 0
-------------------------------------
select object_type, count(*) from admin.big_table group by object_type

Plan hash value: 1753714399

--------------------------------------------------------------------------------------
|Id | Operation                   | Name      | Rows  | Bytes | Cost (%CPU)| Time    |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT            |           |       |       |   257 (100)|         |
| 1 |  HASH GROUP BY              |           |    39 |   351 |   257  (13)| 00:00:01|
| 2 |   TABLE ACCESS INMEMORY FULL| BIG_TABLE |  1000K|  8789K|   233   (4)| 00:00:01|
--------------------------------------------------------------------------------------

Note
-----
   - SQL profile coe_8g28yt7c1nacr_1753714399 used for this statement
   - SQL plan baseline SQL_PLAN_1wn92bz7gqvxx73be0962 used for this statement

Notice "TABLE ACCESS INMEMORY FULL" operation is used instead of "TABLE ACCESS FULL" and both SQL profile and SQL plan baselines are used for this query.

In this case Oracle used in-memory column store to read data without any intervention on SQL profile or SQL plan baseline. Plan hash value remained the same in both cases.


But what if we have index operations involved in execution plan.

-- Temporary disable IM column store to optimise queries
SQL> alter system set inmemory_query=DISABLE;

-- Force Oracle to use index
SQL> alter session set optimizer_index_caching=100;
SQL> alter session set optimizer_index_cost_adj=1;


select object_type, count(*)
from admin.big_table
where object_type > 'C'
group by object_type;



SQL_ID  8xvfvz3axf5ct, child number 0
-------------------------------------
select object_type, count(*) from admin.big_table where object_type >
'C' group by object_type

Plan hash value: 3149057435

-------------------------------------------------------------------------------------
| Id  | Operation            | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |              |       |       |    28 (100)|          |
|   1 |  SORT GROUP BY NOSORT|              |    39 |   351 |    28   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN   | IDX_OBJ_TYPE |  1000K|  8789K|    28   (0)| 00:00:01 |
-------------------------------------------------------------------------------------

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

   2 - access("OBJECT_TYPE">'C')


-- Create SQL plan baseline 

DECLARE
my_plans pls_integer;
BEGIN
  my_plans := DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE(
    sql_id => '8xvfvz3axf5ct');
END;
/

-- Create SQL profile

SQL>@coe_xfr_sql_profile 8xvfvz3axf5ct 3149057435
SQL>@coe_xfr_sql_profile_8xvfvz3axf5ct_3149057435.sql

I have slightly different query with "INDEX RANGE SCAN" operation in execution plan. SQL plan baseline and SQL profile are both created for this query.


In Note section you can see that SQL profile and SQL plan baseline are both used.

select object_type, count(*)
from admin.big_table
where object_type > 'C'
group by object_type;


SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  8xvfvz3axf5ct, child number 0
-------------------------------------
select object_type, count(*) from admin.big_table where object_type >
'C' group by object_type

Plan hash value: 3149057435

-------------------------------------------------------------------------------------
| Id  | Operation            | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |              |       |       |    28 (100)|          |
|   1 |  SORT GROUP BY NOSORT|              |    39 |   351 |    28   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN   | IDX_OBJ_TYPE |  1000K|  8789K|    28   (0)| 00:00:01 |
-------------------------------------------------------------------------------------

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

   2 - access("OBJECT_TYPE">'C')

Note
-----
   - SQL profile coe_8xvfvz3axf5ct_3149057435 used for this statement
   - SQL plan baseline SQL_PLAN_76jwvc1sug4k44391ca35 used for this statement

Enable IM column store to optimise queries.

SQL> alter system set inmemory_query=ENABLE;

System altered.

select object_type, count(*)
from admin.big_table
where object_type > 'C'
group by object_type;

SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  8xvfvz3axf5ct, child number 1
-------------------------------------
select object_type, count(*) from admin.big_table where object_type >
'C' group by object_type

Plan hash value: 3149057435

-------------------------------------------------------------------------------------
| Id  | Operation            | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |              |       |       |    28 (100)|          |
|   1 |  SORT GROUP BY NOSORT|              |    39 |   351 |    28   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN   | IDX_OBJ_TYPE |  1000K|  8789K|    28   (0)| 00:00:01 |
-------------------------------------------------------------------------------------

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

   2 - access("OBJECT_TYPE">'C')

Note
-----
   - SQL profile coe_8xvfvz3axf5ct_3149057435 used for this statement
   - SQL plan baseline SQL_PLAN_76jwvc1sug4k44391ca35 used for this statement

This time in-memory option is not used to improve performance of the query.

Let’s drop SQL profile and leave SQL plan baseline enabled.

exec dbms_sqltune.drop_sql_profile('coe_8xvfvz3axf5ct_3149057435');


elect object_type, count(*)
from admin.big_table
where object_type > 'C'
group by object_type;


Plan hash value: 1753714399

--------------------------------------------------------------------------------------
| Id| Operation                   | Name      | Rows  | Bytes | Cost (%CPU)| Time    |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT            |           |    39 |   351 |   255  (12)| 00:00:01|
| 1 |  HASH GROUP BY              |           |    39 |   351 |   255  (12)| 00:00:01|
|*2 |   TABLE ACCESS INMEMORY FULL| BIG_TABLE |  1000K|  8789K|   231   (3)| 00:00:01|
--------------------------------------------------------------------------------------


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

   2 - inmemory("OBJECT_TYPE">'C')
       filter("OBJECT_TYPE">'C')

Note
-----
   - SQL plan baseline "SQL_PLAN_76jwvc1sug4k473be0962" used for this statement

Note section says that SQL plan baseline is used for this statement, but different than before.
I have "TABLE ACCESS INMEMORY FULL" operation and plan has changed automatically.

In Oracle 12cR1 Adaptive SQL Plan Management is enabled by default. Oracle calculated more efficient plan using in-memory column store and automatically accepted new SQL execution plan for this query. As new SQL plan is added and accepted Oracle was able to change execution plan.

set lines 200
set pages 999
col plan_name for a30
col sql_text for a50 wrap

select plan_name, sql_text, enabled, accepted
from dba_sql_plan_baselines
where sql_text like '%object_type > %';


PLAN_NAME                      SQL_TEXT                                ENA ACC
------------------------------ --------------------------------------- --- ---
SQL_PLAN_76jwvc1sug4k4ebe5b30f select object_type, count(*)            YES NO
                               from admin.big_table
                               where object_type > 'C'
                               group by object_type

SQL_PLAN_76jwvc1sug4k473be0962 select object_type, count(*)            YES YES
                               from admin.big_table
                               where object_type > 'C'
                               group by object_type

SQL_PLAN_76jwvc1sug4k44391ca35 select object_type, count(*)            YES YES
                               from admin.big_table
                               where object_type > 'C'
                               group by object_type

What if I disable adaptive sql plan management to forbid automatically evolving existing baselines.

-- Disable automatic evolving
BEGIN
  DBMS_SPM.set_evolve_task_parameter(
    task_name => 'SYS_AUTO_SPM_EVOLVE_TASK',
    parameter => 'ACCEPT_PLANS',
    value     => 'FALSE');
END;
/

-- Drop SQL plan baseline used for in-memory full scan
DECLARE
  l_plans_dropped  PLS_INTEGER;
BEGIN
  l_plans_dropped := DBMS_SPM.drop_sql_plan_baseline (
    sql_handle => NULL,
    plan_name  => 'SQL_PLAN_76jwvc1sug4k473be0962');
END;
/

In-memory full scan is not used as index range scan operation was specified in existing baseline which is used for query.

select object_type, count(*)
from admin.big_table
where object_type > 'C'
group by object_type;

SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID 8xvfvz3axf5ct, child number 1
-------------------------------------
select object_type, count(*) from admin.big_table where object_type >
'C' group by object_type

Plan hash value: 3149057435

-------------------------------------------------------------------------------------
| Id  | Operation      | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |      |     |     |  28 (100)|     |
|   1 |  SORT GROUP BY NOSORT|      |  39 | 351 |  28   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN   | IDX_OBJ_TYPE |  1000K|  8789K|  28   (0)| 00:00:01 |
-------------------------------------------------------------------------------------

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

   2 - access("OBJECT_TYPE">'C')

Note
-----
   - SQL plan baseline SQL_PLAN_76jwvc1sug4k44391ca35 used for this statement

New plan was added but this time it is not accepted automatically and taken in consideration by the optimizer. We have to manually validate and accept new plan to use it for query executions.

set lines 200
set pages 999
col plan_name for a30
col sql_text for a50 wrap

select plan_name, sql_text, enabled, accepted
from dba_sql_plan_baselines
where sql_text like '%object_type > %';

PLAN_NAME                      SQL_TEXT                                 ENA ACC
------------------------------ ---------------------------------------- --- ---
SQL_PLAN_76jwvc1sug4k4ebe5b30f select object_type, count(*)             YES NO
                               from admin.big_table
                               where object_type > 'C'
                               group by object_type

SQL_PLAN_76jwvc1sug4k473be0962 select object_type, count(*)             YES NO
                               from admin.big_table
                               where object_type > 'C'
                               group by object_type

SQL_PLAN_76jwvc1sug4k44391ca35 select object_type, count(*)             YES YES
                               from admin.big_table
                               where object_type > 'C'
                               group by object_type

What will happen if I have query with hint.

select /*+index(t IDX_OBJ_TYPE)*/  
       object_type, count(*)
from admin.big_table t
where object_type > 'C'
group by object_type;


SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  8k7fykgphx8ra, child number 0
-------------------------------------
select /*+index(t IDX_OBJ_TYPE)*/        object_type, count(*) from
admin.big_table t where object_type > 'C' group by object_type

Plan hash value: 3149057435

-------------------------------------------------------------------------------------
| Id  | Operation            | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |              |       |       |  2770 (100)|          |
|   1 |  SORT GROUP BY NOSORT|              |    39 |   351 |  2770   (1)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN   | IDX_OBJ_TYPE |  1000K|  8789K|  2770   (1)| 00:00:01 |
-------------------------------------------------------------------------------------

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

   2 - access("OBJECT_TYPE">'C')

In-memory data access is ignored as we have hint forcing usage of the index.

select /*+full(t)*/
       object_type, count(*)
from admin.big_table t
where object_type > 'C'
group by object_type;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

Plan hash value: 1753714399

--------------------------------------------------------------------------------------
|Id | Operation                   | Name      | Rows  | Bytes | Cost (%CPU)| Time    |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT            |           |    39 |   351 |   255  (12)| 00:00:01|
| 1 |  HASH GROUP BY              |           |    39 |   351 |   255  (12)| 00:00:01|
|*2 |   TABLE ACCESS INMEMORY FULL| BIG_TABLE |  1000K|  8789K|   231   (3)| 00:00:01|
--------------------------------------------------------------------------------------

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

   2 - inmemory("OBJECT_TYPE">'C')
       filter("OBJECT_TYPE">'C')

In case we have hint forcing full scan, query will read data from in-memory column store as "TABLE ACCESS INMEMORY FULL" and "TABLE ACCESS FULL" are the same full table scan operations for the optimizer.


Conclusion
If your production application is heavily dependent on SQL profiles and SQL hints it would be hard to use full potential of in-memory column store option in a short time.
With SQL plan baselines it is slightly easier because you could use Adaptive SQL Plan Management to alter plans.

But you must dedicate some time for proper testing, because changing plans and dropping indexes blindly could cause many performance problems.

Read more →

Reduce Hard Parse time using SQL Profile

Few days ago we had concurrency problem with "cursor: pin S wait on X" wait event. This wait event is mostly associated with parsing in some form.

After quick diagnosis I’ve found problematic query. It was fairly complex query which was executed very often with average 0.20 seconds of execution time. As this query was using bind variables, Oracle reused existing plan and problems with "cursor: pin S wait on X" wait events weren’t appearing.

But when hard parse occurred we experienced problems with specified mutex waits. Query execution with hard parsing jumped from 0.20 seconds to over 2,1 seconds.

One session would hold mutex pin in exclusive mode while other sessions were waiting to get a mutex pin in share mode - waiting with "Cursor: pin S wait on X" wait event.

Rewriting query would solve this issue but we needed some solution quickly.


I have decided to perform few tests using SQL plan baselines and SQL profiles and measure effect on hard parse. Tested query is intentionally excluded from the post.

Version : Oracle 12.1.0.2

Query execution statistics:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      1.15       2.09          0         10          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.01          0        177          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      1.16       2.11          0        187          0           1

Statistics
----------------------------------------------------------
       1691  recursive calls
          0  db block gets
       1594  consistent gets
          0  physical reads
          0  redo size
       7266  bytes sent via SQL*Net to client
       8393  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
         60  sorts (memory)
          0  sorts (disk)
          1  rows processed

Total query execution is 2.11 seconds where parsing took 2.09 seconds which is practically whole query execution time.


What will happen if we create fixed baseline for the query:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      1.15       2.09          0          7          0           0
Execute      1      0.00       0.00          0          0          1           0
Fetch        2      0.00       0.01          0        177          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      1.16       2.11          0        184          1           1

Note
-----
   - SQL plan baseline "SQL_PLAN_6q3anxq5dfsj4e57c1833" used for this statement

Statistics
----------------------------------------------------------
       1691  recursive calls
          0  db block gets
       1594  consistent gets
          0  physical reads
          0  redo size
       7287  bytes sent via SQL*Net to client
       8393  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
         60  sorts (memory)
          0  sorts (disk)
          1  rows processed

I have practically the same results which means that SQL plan baseline had no effect on parse time.


But, what will happen if I create SQL profile instead of baseline:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.65       1.21          6         21          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.01       0.01          0        177          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.66       1.23          6        198          0           1

Note
-----
   - SQL profile "PROFILE_09vf7nstqk7n2" used for this statement

Statistics
----------------------------------------------------------
        654  recursive calls
          0  db block gets
       1300  consistent gets
          6  physical reads
          0  redo size
       7284  bytes sent via SQL*Net to client
       8393  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
         60  sorts (memory)
          0  sorts (disk)
          1  rows processed

This is big improvement.
Notice elapsed time for parse - from 2.09 secs to 1.21 secs.
Check query statistics - almost three times less recursive calls.


But why?
This is my explanation and I might be wrong so please leave comment below if this is the case.

When we’re using SQL baselines for plan management first step is always generating execution plans from optimizer. Cost based optimizer produces several plans and then compares plans with plans in the SQL plan baseline. Many different plans will be probed as a part of optimizer calculations. SQL plan baseline has no effect on number of calculations.

With SQL profiles we will feed optimizer with estimations and hints before calculation starts. Future plan will be influenced by the SQL profile. Basically we will point optimizer "in the right direction" and optimizer will not perform the same amount of calculations like before. As a result we have less recursive calls and less time spent on hard parsing.


After "fixing" plan with SQL profile, I’ve tried to reproduce mutex concurrency intentionally forcing hard parse but now Oracle managed to perform hard parse without affecting many sessions. Maybe I’ve solved problem temporarily and bought some time for developers to rewrite problematic query.

Read more →

Using Adaptive Cursors Sharing with SQL Plan Baselines

We have several databases where automatic capturing of sql plan baselines is enabled for a few schemas.

Execution of some queries deeply depend on variables where is not always the best to reuse same execution plan for all executions. For those queries I want to avoid using literals and inefficient execution plans. Also, I want to use SQL plan baselines as I have automatic capturing enabled.

Question is, can I make Adaptive Cursor Sharing to work with SQL Plan Baselines without changing query?
Activate bind awareness for every execution to avoid inefficient execution plans?

I want to avoid even one inefficient execution or wait for ACS kick in automatically, because this one lousy execution could be potentially big problem.


For demo case I’m using 1000000 rows table with skewed data:

SQL> select * from v$version;

BANNER                                                                               CON_ID
-------------------------------------------------------------------------------- ----------
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production              0
PL/SQL Release 12.1.0.2.0 - Production                                                    0
CORE    12.1.0.2.0      Production                                                        0
TNS for IBM/AIX RISC System/6000: Version 12.1.0.2.0 - Production                         0
NLSRTL Version 12.1.0.2.0 - Production                                                    0


select owner, count(*)
from big_table
group by owner;

OWNER        COUNT(*)
---------- ----------
MDSYS               1
PUBLIC         499999
SYS            499999
ORDSYS              1


create index IDX_OWNER on BIG_TABLE(owner);

begin
  dbms_stats.gather_table_stats(ownname=>'MSUTIC',tabname=>'BIG_TABLE',cascade=>TRUE, estimate_percent=>100, method_opt=>'for columns size 4 owner');
end;
/

This is my test query.

SQL> var own varchar2(10);
SQL> exec :own := 'SYS';

select owner, sum(object_id)
from big_table
where owner = :own
group by owner;


SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));


SQL_ID  5cdba9s9mkag7, child number 0
-------------------------------------
select owner, sum(object_id) from big_table where owner = :own group by
owner

Plan hash value: 2943376087

----------------------------------------------------------------------------------
| Id  | Operation            | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |           |       |       |  3552 (100)|          |
|   1 |  SORT GROUP BY NOSORT|           |   499K|  9277K|  3552   (1)| 00:00:01 |
|*  2 |   TABLE ACCESS FULL  | BIG_TABLE |   499K|  9277K|  3552   (1)| 00:00:01 |
----------------------------------------------------------------------------------

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

   2 - filter("OWNER"=:OWN)

For a first execution bind sensitivity is enabled because I have gathered statistics with histogram.

select     sql_id
    ,      is_bind_aware 
    ,      is_bind_sensitive
    ,      is_shareable
    ,      plan_hash_value
    from   v$sql  
    where  sql_id = '5cdba9s9mkag7';
 
SQL_ID        I I I PLAN_HASH_VALUE
------------- - - - ---------------
5cdba9s9mkag7 N Y Y      2943376087

To enable bind awareness I want to insert BIND_AWARE hint without changing query.

I will use SQL Patch for this:

SQL> begin
  sys.dbms_sqldiag_internal.i_create_patch(
     sql_text => 'select owner, sum(object_id)
                  from big_table
                  where owner = :own
                  group by owner',
     hint_text => 'BIND_AWARE',
     name      => 'bind_aware_patch');
end;
/  2    3    4    5    6    7    8    9   10

PL/SQL procedure successfully completed.

Now let’s check execution and bind awareness for the query.

SQL> var own varchar2(10);
SQL> exec :own := 'SYS';

select owner, sum(object_id)
from big_table
where owner = :own
group by owner;


SQL_ID  5cdba9s9mkag7, child number 0
-------------------------------------
select owner, sum(object_id) from big_table where owner = :own group by
owner

Plan hash value: 2943376087

----------------------------------------------------------------------------------
| Id  | Operation            | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |           |       |       |  3552 (100)|          |
|   1 |  SORT GROUP BY NOSORT|           |   499K|  9277K|  3552   (1)| 00:00:01 |
|*  2 |   TABLE ACCESS FULL  | BIG_TABLE |   499K|  9277K|  3552   (1)| 00:00:01 |
----------------------------------------------------------------------------------

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

   2 - filter("OWNER"=:OWN)

Note
-----
   - SQL patch "bind_aware_patch" used for this statement
   
   
select     sql_id
    ,      is_bind_aware 
    ,      is_bind_sensitive
    ,      is_shareable
    ,      plan_hash_value
    from   v$sql  
    where  sql_id = '5cdba9s9mkag7';
 
 
SQL_ID        I I I PLAN_HASH_VALUE
------------- - - - ---------------
5cdba9s9mkag7 Y Y Y      2943376087

We have note that SQL patch is used and we have bind awareness enabled. For every query execution, during hard parse, Oracle will peak variable and calculate efficient execution plan accordingly. At least, I would expect this.


Let’s try with another variable - will Oracle alter execution plan.

SQL> var own varchar2(10);
SQL> exec :own := 'MDSYS';
   
   
select owner, sum(object_id)
from big_table
where owner = :own
group by owner;
   

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));   


SQL_ID  5cdba9s9mkag7, child number 1
-------------------------------------
select owner, sum(object_id) from big_table where owner = :own group by
owner

Plan hash value: 1772680857

------------------------------------------------------------------------------------------
| Id  | Operation                    | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |           |       |       |     4 (100)|          |
|   1 |  SORT GROUP BY NOSORT        |           |     1 |    19 |     4   (0)| 00:00:01 |
|   2 |   TABLE ACCESS BY INDEX ROWID| BIG_TABLE |     1 |    19 |     4   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | IDX_OWNER |     1 |       |     3   (0)| 00:00:01 |
------------------------------------------------------------------------------------------

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

   3 - access("OWNER"=:OWN)

Note
-----
   - SQL patch "bind_aware_patch" used for this statement


   
select     sql_id
    ,      is_bind_aware 
    ,      is_bind_sensitive
    ,      is_shareable
    ,      plan_hash_value
    from   v$sql  
    where  sql_id = '5cdba9s9mkag7';
   
   
SQL_ID        I I I PLAN_HASH_VALUE
------------- - - - ---------------
5cdba9s9mkag7 Y Y Y      2943376087
5cdba9s9mkag7 Y Y Y      1772680857

Notice how Oracle changed execution plan and now we have two plans for specified sql text.


Capture SQL plans from cursor cache to create baseline.

DECLARE
my_plans pls_integer;
BEGIN
  my_plans := DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE(
    sql_id => '5cdba9s9mkag7');
END;
/

We have two ACCEPTED plans saved for this query which Oracle will consider during execution, and SQL patch forcing bind awareness.

set lines 200
col sql_handle for a25
col plan_name  for a35
select sql_handle, plan_name, enabled, accepted, fixed 
from dba_sql_plan_baselines
where sql_handle='SQL_f02626d2f3cad6cc';

SQL_HANDLE                PLAN_NAME                           ENA ACC FIX
------------------------- ----------------------------------- --- --- ---
SQL_f02626d2f3cad6cc      SQL_PLAN_g09j6ubtwppqc69a8f699      YES YES NO 
SQL_f02626d2f3cad6cc      SQL_PLAN_g09j6ubtwppqcaf705ad7      YES YES NO 

Now we will perform test to check will Oracle alter execution plan on variable value.

SQL> var own varchar2(10);
SQL> exec :own := 'SYS';

select owner, sum(object_id)
from big_table
where owner = :own
group by owner;

OWNER                            SUM(OBJECT_ID)
-------------------------------- --------------
SYS                                  7.5387E+10

SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  5cdba9s9mkag7, child number 0
-------------------------------------
select owner, sum(object_id) from big_table where owner = :own group by
owner

Plan hash value: 2943376087

----------------------------------------------------------------------------------
| Id  | Operation            | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |           |       |       |  3552 (100)|          |
|   1 |  SORT GROUP BY NOSORT|           |   499K|  9277K|  3552   (1)| 00:00:01 |
|*  2 |   TABLE ACCESS FULL  | BIG_TABLE |   499K|  9277K|  3552   (1)| 00:00:01 |
----------------------------------------------------------------------------------

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

   2 - filter("OWNER"=:OWN)

Note
-----
   - SQL patch "bind_aware_patch" used for this statement
   - SQL plan baseline SQL_PLAN_g09j6ubtwppqcaf705ad7 used for this statement

Oracle used SQL patch and SQL plan baseline.

What if I change variable value.

SQL> var own varchar2(10);
SQL> exec :own := 'MDSYS';

select owner, sum(object_id)
from big_table
where owner = :own
group by owner;

OWNER                            SUM(OBJECT_ID)
-------------------------------- --------------
MDSYS                                    182924

SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(format => 'TYPICAL'));

SQL_ID  5cdba9s9mkag7, child number 1
-------------------------------------
select owner, sum(object_id) from big_table where owner = :own group by
owner

Plan hash value: 1772680857

------------------------------------------------------------------------------------------
| Id  | Operation                    | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |           |       |       |     4 (100)|          |
|   1 |  SORT GROUP BY NOSORT        |           |     1 |    19 |     4   (0)| 00:00:01 |
|   2 |   TABLE ACCESS BY INDEX ROWID| BIG_TABLE |     1 |    19 |     4   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | IDX_OWNER |     1 |       |     3   (0)| 00:00:01 |
------------------------------------------------------------------------------------------

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

   3 - access("OWNER"=:OWN)

Note
-----
   - SQL patch "bind_aware_patch" used for this statement
   - SQL plan baseline SQL_PLAN_g09j6ubtwppqc69a8f699 used for this statement

Oracle immediately changed execution plan and used different SQL plan baseline.


At the end I have original query with bind variables, I have SQL plan baselines captured, and I’m using powerful ACS feature to have efficient plans for different variables.

Read more →

Unindexed Foreign Keys on empty/unused table and locks

It is widely known that unindexed foreign keys can be performance issue. Unindexed foreign keys on child tables can cause table locks or performance problems in general.
There are many articles on this subject so I won't go in details.

My plan is to show simple demo case where empty child table with unindexed foreign key column can cause big problems.


Imagine that you have highly active table (supplier) with lots DML operations from many sessions.
In the meantime someone created new child table (product) in relationship with parent table (supplier). This table is empty and unused so why should you bother about indexing foreign key columns on empty table.

I will show you case where this empty table can cause lock contention and serious performance issues.

Oracle version - 11.2.0.4.0

CREATE TABLE supplier 
( id number(10) not null,
  supplier_id number(10) not null, 
  supplier_name varchar2(50) not null, 
  contact_name varchar2(50), 
CONSTRAINT id_pk PRIMARY KEY (id),
CONSTRAINT supplier_uk UNIQUE(supplier_id)
); 


INSERT INTO supplier VALUES (1,100, 'Supplier 1', 'Contact 1'); 
INSERT INTO supplier VALUES (2,200, 'Supplier 2', 'Contact 2'); 

COMMIT; 



CREATE TABLE product 
( product_id number(10) not null, 
product_name varchar2(50) not null, 
supplier_id number(10) not null, 
CONSTRAINT fk_supplier 
FOREIGN KEY (supplier_id) 
REFERENCES supplier(supplier_id)
 ); 
  
 
 
SQL> select id, supplier_id, supplier_name, contact_name from supplier;

        ID SUPPLIER_ID SUPPLIER_NAME                                      CONTACT_NAME
---------- ----------- -------------------------------------------------- ------------
         1         100 Supplier 1                                         Contact 1
         2         200 Supplier 2                                         Contact 2
    
    
-- Product table is empty and unused
SQL> select product_id, product_name, supplier_id from product;

no rows selected

User from SESSION1 inserts row and waits some time to end transaction.

--SESSION 1:
INSERT INTO supplier VALUES (3,300, 'Supplier 3', 'Contact 3'); --(Without COMMIT)
1 row created.

In the same time there are lots sessions which are trying to update record with column used in foreign-key relationship. All sessions are hanging and you have big problem.

--SESSION 2:
UPDATE supplier SET supplier_id=200 WHERE supplier_id = 200;  --(HANG)

Let's try another INSERT in next session:

--SESSION 3:
INSERT INTO supplier VALUES (4,400, 'Supplier 4', 'Contact 4');  --(HANG)

Now we have inserts hanging which could lead to major problems for very active table.

Check locks:

SELECT l.sid, s.blocking_session blocker, s.event, l.type, l.lmode, 
       l.request, o.object_name, o.object_type 
FROM v$lock l, dba_objects o, v$session s 
WHERE UPPER(s.username) = UPPER('MSUTIC') 
AND l.id1 = o.object_id (+) 
AND l.sid = s.sid 
ORDER BY sid, type;

       SID    BLOCKER EVENT                                 TY      LMODE    REQUEST OBJECT_NAME                 OBJECT_TYPE
---------- ---------- -------------------------------------- -- ---------- ---------- -------------------------- ------------
        63       1641 enq: TM - contention                   AE          4          0 ORA$BASE                    EDITION
        63       1641 enq: TM - contention                   TM          3          0 SUPPLIER                    TABLE
        63       1641 enq: TM - contention                   TM          0          4 PRODUCT                     TABLE
      1390            SQL*Net message to client              AE          4          0 ORA$BASE                    EDITION
      1641            SQL*Net message from client            AE          4          0 ORA$BASE                    EDITION
      1641            SQL*Net message from client            TM          3          0 SUPPLIER                    TABLE
      1641            SQL*Net message from client            TM          3          0 PRODUCT                     TABLE
      1641            SQL*Net message from client            TX          6          0 TPT                         SYNONYM
      2159            SQL*Net message from client            AE          4          0 ORA$BASE                    EDITION
      2729         63 enq: TM - contention                   AE          4          0 ORA$BASE                    EDITION
      2729         63 enq: TM - contention                   TM          0          3 PRODUCT                     TABLE
      2729         63 enq: TM - contention                   TM          3          0 SUPPLIER                    TABLE

Unused and empty product table is culprit for performance issues.


Create index on foreign key column and check behaviour.

CREATE INDEX fk_supplier ON product (supplier_id);

--SESSION 1:
INSERT INTO supplier VALUES (3,300, 'Supplier 3', 'Contact 3');
1 row created.


--SESSION 2:
UPDATE supplier SET supplier_id=200 WHERE supplier_id = 200;
1 row updated.

Now everything worked without locking problems.



Notice that we have different behaviour in 12c version.

Oracle version - 12.1.0.2.0

CREATE TABLE supplier 
( supplier_id number(10) not null, 
  supplier_name varchar2(50) not null, 
  contact_name varchar2(50), 
CONSTRAINT supplier_pk PRIMARY KEY (supplier_id) 
); 

INSERT INTO supplier VALUES (1, 'Supplier 1', 'Contact 1'); 
INSERT INTO supplier VALUES (2, 'Supplier 2', 'Contact 2'); 
COMMIT; 

CREATE TABLE product 
( product_id number(10) not null, 
product_name varchar2(50) not null, 
supplier_id number(10) not null, 
CONSTRAINT fk_supplier 
FOREIGN KEY (supplier_id) 
REFERENCES supplier(supplier_id)
); 
  

--SESSION 1:
INSERT INTO supplier VALUES (3, 'Supplier 3', 'Contact 3'); --(Without COMMIT)
1 row created.

--SESSION 2:
UPDATE supplier SET supplier_id=2 WHERE supplier_id = 2; -- (No HANG)
1 row updated.

Check locks:

SELECT l.sid, s.blocking_session blocker, s.event, l.type, l.lmode,
       l.request, o.object_name, o.object_type 
FROM v$lock l, dba_objects o, v$session s 
WHERE UPPER(s.username) = UPPER('MSUTIC') 
AND l.id1 = o.object_id (+) 
AND l.sid = s.sid 
ORDER BY sid, type;


  SID    BLOCKER EVENT                          TY      LMODE    REQUEST OBJECT_NAME
------ ---------- ------------------------------ -- ---------- ---------- ------------
 4500            SQL*Net message from client    AE          4          0 ORA$BASE
 4500            SQL*Net message from client    TM          3          0 SUPPLIER
 4500            SQL*Net message from client    TX          6          0
 6139            SQL*Net message to client      AE          4          0 ORA$BASE
 6144            SQL*Net message from client    AE          4          0 ORA$BASE
 6144            SQL*Net message from client    TM          3          0 SUPPLIER
 6144            SQL*Net message from client    TM          2          0 PRODUCT
 6144            SQL*Net message from client    TX          6          0

I don't think that you should index all foreign keys all the time. Sometimes this is not needed and it could be overhead. Unnecessary indexes on foreign keys are wasting storage space and cause slower DML operations on the table.

Think about application and how parent/child tables will be used before creating indexes and check articles from Tom Kyte on this subject.





Update 2016-07-08:


Oracle version - 11.2.0.4.0

What if we index column using descending order.

CREATE INDEX fk_supplier ON product (SUPPLIER_ID DESC);

Index created.

--SESSION 1:
INSERT INTO supplier VALUES (3,300, 'Supplier 3', 'Contact 3'); --(Without COMMIT)

--SESSION 2:
UPDATE supplier SET supplier_id=200 WHERE supplier_id = 200;  --(HANG)

--Try another INSERT in next session:

--SESSION 3:
INSERT INTO supplier VALUES (4,400, 'Supplier 4', 'Contact 4');  --(HANG)

Check locks:

SELECT l.sid, s.blocking_session blocker, s.event, l.type, l.lmode, 
       l.request, o.object_name, o.object_type 
FROM v$lock l, dba_objects o, v$session s 
WHERE UPPER(s.username) = UPPER('MSUTIC') 
AND l.id1 = o.object_id (+) 
AND l.sid = s.sid 
ORDER BY sid, type;


   SID    BLOCKER EVENT                          TY      LMODE    REQUEST OBJECT_NAME   OBJECT_TYPE
------ ---------- ------------------------------ -- ---------- ---------- ------------- -----------
   192       1137 enq: TM - contention           AE          4          0 ORA$BASE      EDITION
   192       1137 enq: TM - contention           TM          3          0 SUPPLIER      TABLE
   192       1137 enq: TM - contention           TM          0          3 PRODUCT       TABLE
   382            SQL*Net message from client    AE          4          0 ORA$BASE      EDITION
   949            SQL*Net message from client    AE          4          0 ORA$BASE      EDITION
   949            SQL*Net message from client    TM          3          0 SUPPLIER      TABLE
   949            SQL*Net message from client    TM          3          0 PRODUCT       TABLE
   949            SQL*Net message from client    TX          6          0
  1137        949 enq: TM - contention           AE          4          0 ORA$BASE      EDITION
  1137        949 enq: TM - contention           TM          3          0 SUPPLIER      TABLE
  1137        949 enq: TM - contention           TM          0          4 PRODUCT       TABLE
  1516            SQL*Net message to client      AE          4          0 ORA$BASE      EDITION
  2459            SQL*Net message from client    AE          4          0 ORA$BASE      EDITION

Keep in mind - using descending order for the column to create index will not solve problem with concurrency.

Read more →

How to use index to get NULL values

I have learned new trick today which I want to share and keep as reminder to myself. I am sure that most Oracle DBA’s or Developers are familiar with this - so please skip this post if you are one of them :)


My test table will have 1000000 rows with 1000 NULL values for “OBJECT_NAME” column.

Tests are performed on 11gR1 version.

Table/column info:

select c.table_name, c.column_name, c.data_type, c.num_nulls, 
       t.num_rows table_num_rows
from dba_tab_columns c, dba_tables t
where 1=1
and c.table_name = t.table_name
and c.table_name = 'OBJECTS'
and c.column_name = 'OBJECT_NAME';



TABLE_NAME    COLUMN_NAME     DATA_TYPE     NUM_NULLS TABLE_NUM_ROWS
------------- --------------- ------------ ---------- --------------
OBJECTS       OBJECT_NAME     VARCHAR2           1000        1000000 

Goal:
Count how many OBJECT_NAMEs are NULL.


Index object_name column using classic B-tree index.

create index idx_objname on objects(object_name);


select count(*)
from objects
where object_name is null;

  COUNT(*)
----------
      1000

------------------------------------------------------------------------------
| Id  | Operation          | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |         |       |       |  4252 (100)|          |
|   1 |  SORT AGGREGATE    |         |     1 |    25 |            |          |
|*  2 |   TABLE ACCESS FULL| OBJECTS |  1000 | 25000 |  4252   (1)| 00:00:52 |
------------------------------------------------------------------------------

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

   2 - filter("OBJECT_NAME" IS NULL)
   
   
drop index idx_objname;

FULL SCAN is used because NULL values are not indexed for single column indexes.


For a workaround you could create function based index to help yourself. This was (till now) my preferred option.

create index idx_objname_f on objects(nvl(object_name,'XX'));

select count(*)
from objects
where nvl(object_name,'XX')='XX';

  COUNT(*)
----------
      1000

-----------------------------------------------------------------------------------
| Id  | Operation         | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |               |       |       |     3 (100)|          |
|   1 |  SORT AGGREGATE   |               |     1 |    17 |            |          |
|*  2 |   INDEX RANGE SCAN| IDX_OBJNAME_F | 10000 |   166K|     3   (0)| 00:00:01 |
-----------------------------------------------------------------------------------

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

   2 - access("OBJECTS"."SYS_NC00017$"='XX')

Now INDEX is used but as you can see I had to modify initial query using function to get number of NULLs.

Besides that, this index is unusable if I want to get other values then NULL.

select count(*)
from objects
where object_name='TEST';

  COUNT(*)
----------
        16


------------------------------------------------------------------------------
| Id  | Operation          | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |         |       |       |  4253 (100)|          |
|   1 |  SORT AGGREGATE    |         |     1 |    25 |            |          |
|*  2 |   TABLE ACCESS FULL| OBJECTS |    28 |   700 |  4253   (1)| 00:00:52 |
------------------------------------------------------------------------------

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

   2 - filter("OBJECT_NAME"='TEST')
   
      
drop index idx_objname_f;

The trick that I wanted to show.
In composite index NULL values are stored for leading column when second column is not NULL. I will use dummy value for second column.

create index idx_objname_d on objects(object_name,'X');

select count(*)
from objects
where object_name is null;

  COUNT(*)
----------
      1000

-----------------------------------------------------------------------------------
| Id  | Operation         | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |               |       |       |     8 (100)|          |
|   1 |  SORT AGGREGATE   |               |     1 |    25 |            |          |
|*  2 |   INDEX RANGE SCAN| IDX_OBJNAME_D |  1000 | 25000 |     8   (0)| 00:00:01 |
-----------------------------------------------------------------------------------

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

   2 - access("OBJECT_NAME" IS NULL)

Index is used to count NULL values.


You can also use this index to get other values.

select count(*)
from objects
where object_name='TEST';

  COUNT(*)
----------
        16

-----------------------------------------------------------------------------------
| Id  | Operation         | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |               |       |       |     3 (100)|          |
|   1 |  SORT AGGREGATE   |               |     1 |    25 |            |          |
|*  2 |   INDEX RANGE SCAN| IDX_OBJNAME_D |    28 |   700 |     3   (0)| 00:00:01 |
-----------------------------------------------------------------------------------

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

   2 - access("OBJECT_NAME"='TEST')


drop index idx_objname_d;

This trick was so nice discovery for me that deserved blog post.


It is worth to mention that bitmap index also stores NULL values.

create bitmap index idx_objname_d on objects(object_name);

select count(*)
from objects
where object_name is null;

  COUNT(*)
----------
      1000
   
---------------------------------------------------------------------------------------------
| Id  | Operation                   | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |               |       |       |     3 (100)|          |
|   1 |  SORT AGGREGATE             |               |     1 |    25 |            |          |
|   2 |   BITMAP CONVERSION COUNT   |               |  1000 | 25000 |     3   (0)| 00:00:01 |
|*  3 |    BITMAP INDEX SINGLE VALUE| IDX_OBJNAME_D |       |       |            |          |
---------------------------------------------------------------------------------------------

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

   3 - access("OBJECT_NAME" IS NULL)

Clean up!

drop table objects;

Read more →

Automatic Workload Repository (AWR) space usage

AWR is very powerful diagnostic tool which is used for problem detection and tuning. By default, snapshots of database performance statistics and metrics are taken every hour, retained for 7 days and stored in SYSAUX tablespace.

If possible, I prefer to change default settings to increase retention period and reduce snapshot interval. Before changing default values it is important to think about space consumption by the Automatic Workload Repository.


Nice tool for estimating amount of space required for the SYSAUX tablespace is - utlsyxsz.sql stored in “$ORACLE_HOME/rdbms/admin” directory.


In this example I will estimate size of AWR data with 15 min intervals and 60 days of retention.

This script estimates the space required for the SYSAUX tablespace.
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Specify the Report File Name
~~~~~~~~~~~~~~~~~~~~~~~~~~~~
The default report file name is utlsyxsz.txt. To use this name,
press to continue, otherwise enter an alternative.

Enter value for report_name: /tmp/estimate_awr.out

Using the report name /tmp/estimate_awr.out
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
SYSAUX Size Estimation Report
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Estimated at
10:03:56 on Srp 21, 2010 ( Srijeda ) in Timezone +02:00


DB_NAME HOST_PLATFORM INST STARTUP_TIME PAR
----------- ---------------------------------------- ----- ----------------- ---
* TESTDB l01test1 - Linux IA (32-bit) 1 22:08:09 (10/13) NO

~~~~~~~~~~~~~~~~~~~~
Current SYSAUX usage
~~~~~~~~~~~~~~~~~~~~
| Total SYSAUX size: 653.9 MB
|
| Total size of SM/AWR 334.8 MB ( 51.2% of SYSAUX )
| Total size of SM/OPTSTAT 104.2 MB ( 15.9% of SYSAUX )
| Total size of EM 48.8 MB ( 7.5% of SYSAUX )
| Total size of XDB 48.2 MB ( 7.4% of SYSAUX )
| Total size of SM/ADVISOR 45.2 MB ( 6.9% of SYSAUX )
| Total size of SDO 33.1 MB ( 5.1% of SYSAUX )
| Total size of WM 7.1 MB ( 1.1% of SYSAUX )
| Total size of LOGMNR 5.9 MB ( 0.9% of SYSAUX )
| Total size of SM/OTHER 4.9 MB ( 0.8% of SYSAUX )
| Total size of TEXT 4.6 MB ( 0.7% of SYSAUX )
| Total size of EXPRESSION_FILTER 3.6 MB ( 0.6% of SYSAUX )
| Total size of EM_MONITORING_USER 1.6 MB ( 0.2% of SYSAUX )
| Total size of LOGSTDBY 0.9 MB ( 0.1% of SYSAUX )
| Total size of XSOQHIST 0.8 MB ( 0.1% of SYSAUX )
| Total size of AO 0.8 MB ( 0.1% of SYSAUX )
| Total size of JOB_SCHEDULER 0.8 MB ( 0.1% of SYSAUX )
| Total size of ORDIM 0.5 MB ( 0.1% of SYSAUX )
| Total size of STREAMS 0.5 MB ( 0.1% of SYSAUX )
| Total size of TSM 0.3 MB ( 0.0% of SYSAUX )
| Total size of ODM 0.3 MB ( 0.0% of SYSAUX )
| Total size of Others 7.2 MB ( 1.1% of SYSAUX )
|

~~~~~~~~~~~~~~~~~~~~
AWR Space Estimation
~~~~~~~~~~~~~~~~~~~~

| To estimate the size of the Automatic Workload Repository (AWR)
| in SYSAUX, we need the following values:
|
| - Interval Setting (minutes)
| - Retention Setting (days)
| - Number of Instances
| - Average Number of Active Sessions
| - Number of Datafiles

|
| For 'Interval Setting',
| Press [return] to use the current value: 60.0 minutes
| otherwise enter an alternative
|
Enter value for interval: 15

** Value for 'Interval Setting': 15

|
| For 'Retention Setting',
| Press [return] to use the current value: 30.0 days
| otherwise enter an alternative
|
Enter value for retention: 60

** Value for 'Retention Setting': 60

|
| For 'Number of Instances',
| Press [return] to use the current value: 1.00
| otherwise enter an alternative
|
Enter value for num_instances: 1

** Value for 'Number of Instances': 1

|
| For 'Average Number of Active Sessions',
| Press [return] to use the current value: 0.43
| otherwise enter an alternative
|
Enter value for active_sessions:

** Value for 'Average Number of Active Sessions': .43

| ***************************************************
| Estimated size of AWR: 2,816.7 MB
|
| The AWR estimate was computed using
| the following values:
|
| Interval - 15 minutes
| Retention - 60.00 days
| Num Instances - 1
| Active Sessions - 0.43
| Datafiles - 17
| ***************************************************

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Optimizer Stat History Space Estimation
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

| To estimate the size of the Optimizer Statistics History
| we need the following values:
|
| - Number of Tables in the Database
| - Number of Partitions in the Database
| - Statistics Retention Period (days)
| - DML Activity in the Database (level)

|
| For 'Number of Tables',
| Press [return] to use the current value: 463.0
| otherwise enter an alternative [a positive integer]
|
Enter value for number_of_tables:

** Value for 'Number of Tables': 463

|
| For 'Number of Partitions',
| Press [return] to use the current value: 0.00
| otherwise enter an alternative [a positive integer]
|
Enter value for number_of_partitions:

** Value for 'Number of Partitions': 0

|
| For 'Statistics Retention',
| Press [return] to use the current value: 31.0 days
| otherwise enter an alternative [a positive integer]
|
Enter value for stats_retention:

** Value for 'Statistics Retention': 31

|
| For 'DML Activity',
| Press [return] to use the current value: 2 [medium]
| otherwise enter an alternative [1=low, 2=medium, 3=high]
|
Enter value for dml_activity:

** Value for 'DML Activity': 2

| ***************************************************
| Estimated size of Stats history 33.4 MB
|
| The space for Optimizer Statistics history was
| estimated using the following values:
|
| Tables - 463
| Indexes - 496
| Columns - 5,734
| Partitions - 0
| Indexes on Partitions - 0
| Columns in Partitions - 0
| Stats Retention in Days - 31
| Level of DML Activity - Medium
| ***************************************************

~~~~~~~~~~~~~~~~~~~~~~
Estimated SYSAUX usage
~~~~~~~~~~~~~~~~~~~~~~

| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
| Estimated size of AWR: 2,816.7 MB
|
| The AWR estimate was computed using
| the following values:
|
| Interval - 15 minutes
| Retention - 60.00 days
| Num Instances - 1
| Active Sessions - 0.43
| Datafiles - 17
| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
| Estimated size of Stats history 33.4 MB
|
| The space for Optimizer Statistics history was
| estimated using the following values:
|
| Tables - 463
| Indexes - 496
| Columns - 5,734
| Partitions - 0
| Indexes on Partitions - 0
| Columns in Partitions - 0
| Stats Retention in Days - 31
| Level of DML Activity - Medium
| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
| For all the other components, the estimate
| is equal to the current space usage of
| the component.
| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
|
|
| ***************************************************
| Summary of SYSAUX Space Estimation
| ***************************************************

| Est size of EM 48.8 MB
| Est size of XDB 48.2 MB
| Est size of SM/ADVISOR 45.2 MB
| Est size of SDO 33.1 MB
| Est size of WM 7.1 MB
| Est size of LOGMNR 5.9 MB
| Est size of SM/OTHER 4.9 MB
| Est size of TEXT 4.6 MB
| Est size of EXPRESSION_FILTER 3.6 MB
| Est size of EM_MONITORING_USER 1.6 MB
| Est size of LOGSTDBY 0.9 MB
| Est size of XSOQHIST 0.8 MB
| Est size of AO 0.8 MB
| Est size of JOB_SCHEDULER 0.8 MB
| Est size of ORDIM 0.5 MB
| Est size of STREAMS 0.5 MB
| Est size of TSM 0.3 MB
| Est size of ODM 0.3 MB
| Est size of Others 7.2 MB

| Est size of SM/AWR 2,816.7 MB
| Est size of SM/OPTSTAT 33.4 MB
|
| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
| Total Estimated SYSAUX size: 3,065.0 MB
| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
| ***************************************************

End of Report

Another nice script to mention - awrinfo.sql stored in “$ORACLE_HOME/rdmbs/admin” directory. This script displays general AWR information such as current space usage, data distribution, etc. I like to check space usage with awrinfo.sql script when SYSAUX starts to increase rapidly.

Read more →

Tracing AUTOEXTEND tablespace

In this blog post I will try to examine how AUTOEXTEND operation can affect on performance. Hemant K Chitale already wrote nice article on this subject : AUTOEXTEND ON Next Size, where he wrote about Oracle "default" Autoextend NEXT size.

This topic "Autoextend or not?" from Oracle-L mailing list is great addition to this blog post. You can read there about different usages of AUTOEXTEND option in real life experience of some very good DBA's.



I will perform small test case using 10046 trace to get more information.

For my testing purposes I will use:

SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Prod
PL/SQL Release 10.2.0.4.0 - Production
CORE    10.2.0.4.0      Production
TNS for Linux: Version 10.2.0.4.0 - Production
NLSRTL Version 10.2.0.4.0 - Production


SQL> select log_mode from v$database;

LOG_MODE
------------
NOARCHIVELOG


$ uname -a
Linux linux2.loc 2.6.18-128.el5 #1 SMP Wed Jan 21 07:58:05 EST 2009 i686 i686 i386 GNU/Linux

First to create three different tablespaces with one table in each tablespace.

CREATE TABLESPACE TESTTBS1 DATAFILE
'/oradata/testtbs1.dbf' SIZE 5M AUTOEXTEND ON NEXT 56K MAXSIZE UNLIMITED
LOGGING
ONLINE
PERMANENT
EXTENT MANAGEMENT LOCAL AUTOALLOCATE
BLOCKSIZE 8K
SEGMENT SPACE MANAGEMENT AUTO
FLASHBACK ON;

create table big_table1 tablespace testtbs1
as
select rownum id, a.*
from all_objects a
where 1=0
/



CREATE TABLESPACE TESTTBS2 DATAFILE
'/oradata/testtbs3.dbf' SIZE 5M AUTOEXTEND ON NEXT 25M MAXSIZE UNLIMITED
LOGGING
ONLINE
PERMANENT
EXTENT MANAGEMENT LOCAL AUTOALLOCATE
BLOCKSIZE 8K
SEGMENT SPACE MANAGEMENT AUTO
FLASHBACK ON;

create table big_table2 tablespace testtbs2
as
select rownum id, a.*
from all_objects a
where 1=0
/


CREATE TABLESPACE TESTTBS3 DATAFILE
'/oradata/testtbs2.dbf' SIZE 500M AUTOEXTEND OFF
LOGGING
ONLINE
PERMANENT
EXTENT MANAGEMENT LOCAL AUTOALLOCATE
BLOCKSIZE 8K
SEGMENT SPACE MANAGEMENT AUTO
FLASHBACK ON;

create table big_table3 tablespace testtbs3
as
select rownum id, a.*
from all_objects a
where 1=0
/

I will execute script below to insert 2000000 rows in every table (about 232 MB). This is script from Tom Kyte but just little modified.

SQL> declare
2          l_cnt number;
3          l_rows number := &1;
4  begin
5          insert
6          into big_table1
7          select rownum, a.*
8          from all_objects a
9          where rownum <= &1;
10
11          l_cnt := sql%rowcount;
12
13          commit;
14
15          while (l_cnt < l_rows)
16          loop
17                  insert into big_table1
18                  select rownum+l_cnt,
19                  OWNER,OBJECT_NAME,SUBOBJECT_NAME,OBJECT_ID, DATA_OBJECT_ID,OBJECT_TYPE,
20                  CREATED,LAST_DDL_TIME,TIMESTAMP,STATUS,TEMPORARY,GENERATED,SECONDARY
21                  from big_table1
22                  where rownum <= l_rows - l_cnt;
23                  l_cnt := l_cnt + sql%rowcount;
24                  commit;
25          end loop;
26  end;
27  /
Enter value for 1: 2000000
old   3:         l_rows number := &1;
new   3:         l_rows number := 2000000;
Enter value for 1: 2000000
old   9:         where rownum <= &1;
new   9:         where rownum <= 2000000;

My intention is to trace every script execution and to extract wait statistics from trace file using tkprof tool. First execution with AUTOEXTEND ON NEXT 56K:

Elapsed: 00:00:51.40

Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
control file sequential read                 2187        0.40         24.20
db file sequential read                       162        0.06          1.29
change tracking file synchronous read         891        0.03          1.72
Data file init write                          390        0.34          5.99
db file single write                           81        0.00          0.02
control file parallel write                   243        0.00          0.17
rdbms ipc reply                                81        0.07          0.86
log file switch completion                      7        0.97          1.28
enq: CF - contention                            1        0.00          0.00
log buffer space                                1        0.04          0.04
log file switch (checkpoint incomplete)         3        0.97          1.09

Second execution with AUTOEXTEND ON NEXT 25M:

Elapsed: 00:00:35.13

Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
db file sequential read                        26        0.03          0.28
control file sequential read                  243        0.23          4.91
change tracking file synchronous read          99        0.01          0.19
Data file init write                          243        0.31          6.52
db file single write                            9        0.00          0.00
control file parallel write                    27        0.00          0.01
rdbms ipc reply                                 9        0.16          0.25
log buffer space                               38        0.41          6.72
log file switch completion                      5        0.97          1.74
log file switch (checkpoint incomplete)         5        0.97          1.16

Third execution with AUTOEXTEND OFF:

Elapsed: 00:00:33.93

Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
log file switch completion                      8        0.97          3.50
log file switch (checkpoint incomplete)        12        0.97          5.38
log buffer space                               42        0.82         13.58

About main wait events in my test cases: "control file sequential read" - process is waiting for blocks to be read from control file. "Data file init write" - occurs when Oracle auto extends datafile and formats the newly created space within the datafile. ... Interesting results if you ask me. I expected "Data file int write" wait event because it is closely related to datafile extensions, but "control file sequential read" event little surprised me. To get some better explanation why "control file sequential read" is related to auto extensions I tried to use Metalink but Metalink is not working very well during weekend because of upgrade process. Maybe I'll find more info later using newly upgraded Metalink. To conclude, different autoextend next sizes can significantly affect on overall performance so it is important to set proper value. References: Ask DBSpecialists: 'Data file init write' wait event

Read more →

SQL Tuning - using USE_HASH hint - dblink issue

Colleague noticed that execution of his job lasted too long so he asked me to check out his query - maybe I could improve performance.

So I'll blog about my steps diagnosing and resolving this issue.
{ I've changed table names because they are not important for this example }

Oracle 9.2.0.6.0
Solaris 64

SQL> select count(*) from user1.table1;

COUNT(*)
----------
597259

SQL> select count(*) from user1.table2;

COUNT(*)
----------
2609503

SQL> select count(*) from user2.table3@rm_db;

COUNT(*)
----------
538512

SQL> select count(*) from user1.table4;

COUNT(*)
----------
93

First to check initial query and what was explain plan telling me.

SQL> explain plan for
2  SELECT
3       DISTINCT col1, 0, 0, TRUNC (SYSDATE - 1), t1.c_id
4       FROM user1.table1 t1,
5              user1.table2 t2,
6              user2.table3@rm_db rt
7       WHERE 1 = 1
8       AND t1.c_t = 'ABC'
9       AND t1.c_id = t2.con_id
10       AND t2.status = 'XY'
11       AND ph NOT IN (SELECT ph
12                                 FROM table4)
13       AND t1.c_nr = rt.s_cr
14       AND TRUNC (rt.fut) = TRUNC (SYSDATE - 1);

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------
| Id  | Operation                     |  Name  | Rows  | Bytes | Cost  | Inst   |IN-OUT|
----------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |        |     2 |   340 |  8535 |        |      |
|   1 |  SORT UNIQUE                  |        |     2 |   340 |  8523 |        |      |
|   2 |   FILTER                      |        |       |       |       |        |      |
|   3 |    TABLE ACCESS BY INDEX ROWID| TABLE2 |     1 |    12 |     8 |        |      |
|   4 |     NESTED LOOPS              |        |     2 |   340 |  8522 |        |      |
|   5 |      NESTED LOOPS             |        |     2 |   316 |  8507 |        |      |
|   6 |       TABLE ACCESS FULL       | TABLE1 |   157 |  6751 |  8013 |        |      |
|   7 |       REMOTE                  |        |     1 |   115 |     4 | DW_DB  | R->S |
|   8 |      INDEX RANGE SCAN         | IDX_C  |     6 |       |     3 |        |      |
|   9 |    TABLE ACCESS FULL          | TABLE4 |    20 |   540 |     6 |        |      |
----------------------------------------------------------------------------------------

I've executed query and turned tracing on.

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.03       0.12          0          3          1           0
Execute      1      0.00       0.01          0          0          0           0
Fetch        2     88.15     238.90      11396      20206          0         165
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     88.18     239.04      11396      20209          1         165


Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
SQL*Net message to client                       2        0.00          0.00
db file scattered read                       1502        0.50          2.47
SQL*Net message to dblink                  292103        0.00          0.46
SQL*Net message from dblink                292103        1.33        147.04
db file sequential read                      1384        0.44          1.41
latch free                                     98        0.05          0.23
SQL*Net message from client                     2       28.84         28.95
SQL*Net more data to client                     1        0.00          0.00
*****************************************************

Rows     Row Source Operation
-------  ---------------------------------------------------
165  SORT UNIQUE
166   FILTER
166    TABLE ACCESS BY INDEX ROWID TABLE2
1015     NESTED LOOPS
169      NESTED LOOPS
291934       TABLE ACCESS FULL TABLE1
169       REMOTE
845      INDEX RANGE SCAN IDX_C (object id 30818)
0    TABLE ACCESS FULL TABLE4

From this results I could see that bottleneck was network as biggest waits were related to dblink.
To tune that I decided to try USE_HASH hint and use hash join instead of nested loops on remote table.

SQL> explain plan for
2  SELECT /*+USE_HASH(rt t1) */
3       DISTINCT col1, 0, 0, TRUNC (SYSDATE - 1), t1.c_id
4       FROM user1.table1 t1,
5              user1.table2 t2,
6              user2.table3@rm_db rt
7       WHERE 1 = 1
8       AND t1.c_t = 'ABC'
9       AND t1.c_id = t2.con_id
10       AND t2.status = 'XY'
11       AND ph NOT IN (SELECT ph
12                                 FROM table4)
13       AND t1.c_nr = rt.s_cr
14       AND TRUNC (rt.fut) = TRUNC (SYSDATE - 1);

Explained.

SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------
| Id  | Operation                     |  Name  | Rows  | Bytes | Cost  | Inst   |IN-OUT|
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |        |     2 |   340 | 15222 |        |      |
|   1 |  SORT UNIQUE                  |        |     2 |   340 | 15210 |        |      |
|   2 |   FILTER                      |        |       |       |       |        |      |
|   3 |    TABLE ACCESS BY INDEX ROWID| TABLE2 |     1 |    12 |     8 |        |      |
|   4 |     NESTED LOOPS              |        |     2 |   340 | 15209 |        |      |
|   5 |      HASH JOIN                |        |     2 |   316 | 15194 |        |      |
|   6 |       TABLE ACCESS FULL       | TABLE1 |   157 |  6751 |  8013 |        |      |
|   7 |       REMOTE                  |        |  3307 |   371K|  7178 | RM_DB  | R->S |
|   8 |      INDEX RANGE SCAN         | IDX_C  |     6 |       |     3 |        |      |
|   9 |    TABLE ACCESS FULL          | TABLE4 |    20 |   540 |     6 |        |      |
----------------------------------------------------------------------------------------

Hm... this time explain plan shows double cost compare to query without USE_HASH hint.

Trace results:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.03       0.14          0          0          1           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      2.66       4.76      18417      20195          0         165
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      2.69       4.90      18417      20195          1         165


Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
SQL*Net message to client                       2        0.00          0.00
db file scattered read                       1669        0.01          0.25
db file sequential read                       341        0.05          0.40
direct path write                             120        0.00          0.11
SQL*Net message to dblink                       7        0.00          0.00
SQL*Net message from dblink                     7        1.65          1.90
direct path read                              120        0.00          0.00
SQL*Net message from client                     2        0.32          0.32
SQL*Net more data to client                     1        0.00          0.00
***************************************************

Rows     Row Source Operation
-------  ---------------------------------------------------
165  SORT UNIQUE
166   FILTER
166    TABLE ACCESS BY INDEX ROWID TABLE2
1015     NESTED LOOPS
169      HASH JOIN
291938       TABLE ACCESS FULL TABLE1
281       REMOTE
845      INDEX RANGE SCAN IDX_C (object id 30818)
0    TABLE ACCESS FULL TABLE4

As you can see second query finished in 4,90 secs compare to first query which lasted 239.04 secs.
Using USE_HASH hint I resolved network bottleneck as much less data was being sent over the network.

My colleague was very pleased with query performance improvement :)

Read more →

Trace session using login trigger

We have a Web application which is connecting to database, executes some statements and closes after a few secs. It is very hard to trace this sessions and catch what were they doing on database without some help.
To help myself I wrote simple login trigger which starts tracing on login and inserts information about tracefile into the info table.



First to create info table:

SQL> CREATE TABLE login_audit_info
(
logon_time DATE         ,
username   VARCHAR2(100),
tracefile  VARCHAR2(100)
);

Now to create login trigger which catches sessions executed by user "MSUTIC". Of course, you must use different database user. This "MSUTIC" user is used only for testing purposes here.

CREATE OR REPLACE TRIGGER audit_login_trigger
AFTER LOGON ON DATABASE
DECLARE
l_user        dba_users.username%TYPE   := USER;
l_sql         VARCHAR2 (500);
l_tracefile   VARCHAR2 (100);
l_time        DATE;
BEGIN
l_sql :=
'alter session set events '
|| CHR (39)
|| '10046 trace name context forever, level 12'
|| CHR (39);
l_time := SYSDATE;

IF (l_user = 'MSUTIC')
THEN
EXECUTE IMMEDIATE l_sql;

SELECT    pa.VALUE
|| '/'
|| LOWER (SYS_CONTEXT ('userenv', 'instance_name'))
|| '_ora_'
|| p.spid
|| '.trc'
INTO l_tracefile
FROM v$session s, v$process p, v$parameter pa
WHERE pa.NAME = 'user_dump_dest'
AND s.paddr = p.addr
AND s.audsid = SYS_CONTEXT ('USERENV', 'SESSIONID');

INSERT INTO login_audit_info
(logon_time, username, tracefile
)
VALUES (l_time, l_user, l_tracefile
);

COMMIT;
END IF;
END;
/

Now simple test.

$ sqlplus /nolog

SQL*Plus: Release 11.1.0.7.0 - Production on Fri Jun 26 14:22:47 2009

Copyright (c) 1982, 2008, Oracle.  All rights reserved.

SQL> connect msutic@test11
Enter password: ******
Connected.
SQL> select count(*) from test;

COUNT(*)
----------
1

SQL> exit

I executed "select count(*) from test" and made quick logoff.

SQL> set lines 200
SQL> col logon_time for a20
SQL> col username for a15
SQL> col tracefile for a150
SQL> select * from login_audit_info;

SQL> select to_char(logon_time,'dd.mm.yyyy hh24:mi:ss'),username,tracefile from login_audit_info;

TO_CHAR(LOGON_TIME, USERNAME        TRACEFILE
------------------- --------------- ------------------------------------------------------------
26.06.2009 14:25:59 MSUTIC          /oracle/diag/rdbms/test11/test11/trace/test11_ora_31218.trc

As you can see, my trigger fired and inserted one row into the table.

To examine specified trace file:

vi /oracle/diag/rdbms/test11/test11/trace/test11_ora_31218.trc
...
...
*** 2009-06-26 14:26:07.877
WAIT #0: nam='SQL*Net message from client' ela= 8173860 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1246019167877543
=====================
PARSING IN CURSOR #2 len=25 dep=0 uid=84 oct=3 lid=84 tim=1246019167868491 hv=297253644 ad='3ac91a38' sqlid='7b2twsn8vgfsc'
select count(*) from test
END OF STMT
PARSE #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1950795681,tim=1246019167868491
EXEC #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1950795681,tim=1246019167868491
WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1246019167878005
FETCH #2:c=0,e=0,p=0,cr=7,cu=0,mis=0,r=1,dep=0,og=1,plh=1950795681,tim=1246019167868491
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=7 pr=0 pw=0 time=0 us)'
STAT #2 id=2 cnt=1 pid=1 pos=1 obj=76970 op='TABLE ACCESS FULL TEST (cr=7 pr=0 pw=0 time=0 us cost=3 size=0 card=1)'
WAIT #2: nam='SQL*Net message from client' ela= 265 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1246019167878544
FETCH #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1950795681,tim=1246019167868491
WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1952673792 #bytes=1 p3=0 obj#=-1 tim=1246019167878647
...
...

I have valid trace and now I can do detailed examination.

If you don't need tracing any more just disable trigger (don't drop it) and later when you need tracing again just enable it.

alter trigger audit_login_trigger disable;

Read more →

OPTIMIZER_INDEX_COST_ADJ

Parameter "optimizer_index_cost_adj" was firstly introduced way back in Oracle 8.0.5.
This is very tricky parameter that gets used for calculating cost and we could use this parameter for tuning optimizer behavior. Default value of this parameter is 100, at which the optimizer evaluates index access paths at regular cost. Range of values for this parameter is from 1 to 10000. Changing this value you can influence on optimizer to use index access path over full table scan or opposite. Using lower number then 100 you make index access more desirable for CBO because lower values of that parameter are lowering the cost of index access path.

So changing value of this parameter can improve performance of some queries but also it can significantly degrade the performance if index cost is reduced to unrealistic level and indexes are chosen over other more appropriate methods. I will show this in my example.




First I will create testing table with primary key and index.

msutic@TEST11> CREATE TABLE test_tab AS
2  SELECT  level id                                ,
3          ROUND(dbms_random.value(1,9999),0)   Num,
4          sysdate+level Day                       ,
5          dbms_random.string('A',10) Name
6  FROM    dual
7  CONNECT BY level <= 1000000;

Table created.

msutic@TEST11> ALTER TABLE test_tab
2  ADD CONSTRAINT pk_test_tab PRIMARY KEY (id);

Table altered.

msutic@TEST11> CREATE INDEX idx_num ON test_tab(num);

Index created.

msutic@TEST11> begin
2  dbms_stats.gather_table_stats( ownname=>'MSUTIC',
3                                     tabname=>'TEST_TAB',
4                                     cascade => true,
5                                     method_opt => 'for all indexed columns size 251',
6                                     estimate_percent=>dbms_stats.auto_sample_size
7                                   );
8  end;
9  /

PL/SQL procedure successfully completed.

With optimizer_index_cost_adj = 100 I get this result:

msutic@TEST11> select * from test_tab a, test_tab b
2  where a.id=b.id+5000
3  and b.num > 9950;

4867 rows selected.

Elapsed: 00:00:03.18

Execution Plan
----------------------------------------------------------
Plan hash value: 4193374725

-------------------------------------------------------------------------------
| Id  | Operation          | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |          |  5401 |   284K|  2560   (2)| 00:00:31 |
|*  1 |  HASH JOIN         |          |  5401 |   284K|  2560   (2)| 00:00:31 |
|*  2 |   TABLE ACCESS FULL| TEST_TAB |  5401 |   142K|  1277   (2)| 00:00:16 |
|   3 |   TABLE ACCESS FULL| TEST_TAB |  1000K|    25M|  1276   (2)| 00:00:16 |
-------------------------------------------------------------------------------

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

1 - access("A"."ID"="B"."ID"+5000)
2 - filter("B"."NUM">9950)


Statistics
----------------------------------------------------------
1  recursive calls
0  db block gets
9148  consistent gets
9130  physical reads
0  redo size
280578  bytes sent via SQL*Net to client
476  bytes received via SQL*Net from client
11  SQL*Net roundtrips to/from client
0  sorts (memory)
0  sorts (disk)
4867  rows processed

The most appropriate path for executing this query is using full scans of the table. Execution lasted 00:00:03.18 secs and with 9148 consistent gets and 9130 physical reads.

Now I will change parameter to 10 (optimizer_index_cost_adj=10) to make indexes more desirable.

msutic@TEST11> alter session set optimizer_index_cost_adj=10;

Session altered.

msutic@TEST11> select * from test_tab a, test_tab b
2  where a.id=b.id+5000
3  and b.num > 9950;

4867 rows selected.

Elapsed: 00:00:18.26

Execution Plan
----------------------------------------------------------
Plan hash value: 2874762042

-----------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name        | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |             |  5401 |   284K|       |  1249   (1)| 00:00:15 |
|   1 |  MERGE JOIN                   |             |  5401 |   284K|       |  1249   (1)| 00:00:15 |
|   2 |   TABLE ACCESS BY INDEX ROWID | TEST_TAB    |  1000K|    25M|       |   669   (1)| 00:00:09 |
|   3 |    INDEX FULL SCAN            | PK_TEST_TAB |  1000K|       |       |   210   (1)| 00:00:03 |
|*  4 |   SORT JOIN                   |             |  5401 |   142K|   440K|   580   (1)| 00:00:07 |
|   5 |    TABLE ACCESS BY INDEX ROWID| TEST_TAB    |  5401 |   142K|       |   536   (0)| 00:00:07 |
|*  6 |     INDEX RANGE SCAN          | IDX_NUM     |  5401 |       |       |     1   (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------------

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

4 - access("A"."ID"="B"."ID"+5000)
filter("A"."ID"="B"."ID"+5000)
6 - access("B"."NUM">9950)


Statistics
----------------------------------------------------------
1  recursive calls
0  db block gets
11533  consistent gets
8666  physical reads
0  redo size
280578  bytes sent via SQL*Net to client
476  bytes received via SQL*Net from client
11  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
4867  rows processed

Significant performance degradation is more then obvious. Query execution lasted 00:00:18.26 secs with 11533 consistent gets and 8666 physical reads.
You could see that CBO has chosen indexes over full table scans to execute query.

I've executed this example on:

Linux ciciban 2.6.18-92.1.10.el5.centos.plus #1 SMP Thu Aug 7 12:19:36 EDT 2008 i686 i686 i386 GNU/Linux

Oracle version 11.1.0.6.0

I will execute same query on different operating system and different Oracle version just to compare results.
I've already made test table with all settings like on machine before.

msutic@XE> select * from test_tab a, test_tab b
2  where a.id=b.id+5000
3  and b.num > 9950;

4821 rows selected.

Elapsed: 00:00:00.29

Execution Plan
----------------------------------------------------------
Plan hash value: 4193374725

-------------------------------------------------------------------------------
| Id  | Operation          | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |          |  4963 |   261K|  2620   (4)| 00:00:32 |
|*  1 |  HASH JOIN         |          |  4963 |   261K|  2620   (4)| 00:00:32 |
|*  2 |   TABLE ACCESS FULL| TEST_TAB |  4963 |   130K|  1302   (4)| 00:00:16 |
|   3 |   TABLE ACCESS FULL| TEST_TAB |   996K|    25M|  1300   (4)| 00:00:16 |
-------------------------------------------------------------------------------

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

1 - access("A"."ID"="B"."ID"+5000)
2 - filter("B"."NUM">9950)


Statistics
----------------------------------------------------------
0  recursive calls
0  db block gets
9156  consistent gets
0  physical reads
0  redo size
278485  bytes sent via SQL*Net to client
483  bytes received via SQL*Net from client
11  SQL*Net roundtrips to/from client
0  sorts (memory)
0  sorts (disk)
4821  rows processed

With optimizer_index_cost_adj=10:

msutic@XE> alter session set optimizer_index_cost_adj=10;

Session altered.

Elapsed: 00:00:00.12
msutic@XE> select * from test_tab a, test_tab b
2  where a.id=b.id+5000
3  and b.num > 9950;

4821 rows selected.

Elapsed: 00:00:01.31

Execution Plan
----------------------------------------------------------
Plan hash value: 2874762042

---------------------------------------------------------------------------------------------
| Id  | Operation                     | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |             |  4963 |   261K|  1169   (1)| 00:00:15 |
|   1 |  MERGE JOIN                   |             |  4963 |   261K|  1169   (1)| 00:00:15 |
|   2 |   TABLE ACCESS BY INDEX ROWID | TEST_TAB    |   996K|    25M|   673   (2)| 00:00:09 |
|   3 |    INDEX FULL SCAN            | PK_TEST_TAB |   996K|       |   212   (2)| 00:00:03 |
|*  4 |   SORT JOIN                   |             |  4963 |   130K|   496   (1)| 00:00:06 |
|   5 |    TABLE ACCESS BY INDEX ROWID| TEST_TAB    |  4963 |   130K|   495   (1)| 00:00:06 |
|*  6 |     INDEX RANGE SCAN          | IDX_NUM     |  4980 |       |     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------

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

4 - access("A"."ID"="B"."ID"+5000)
filter("A"."ID"="B"."ID"+5000)
6 - access("B"."NUM">9950)


Statistics
----------------------------------------------------------
1  recursive calls
0  db block gets
11483  consistent gets
1  physical reads
0  redo size
278485  bytes sent via SQL*Net to client
483  bytes received via SQL*Net from client
11  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
4821  rows processed

This is executed on Windows XP operating system and Oracle 10.2.0.1.0 version.
Performance degradation on this machine is less obvious then before but still it exists.


Parameter optimizer_index_cost_adj is tightly related with optimizer_index_caching parameter but I will talk more about that parameter in one of next posts.
The big question is what is most appropriate nondefault value for this parameters? One thing is sure that changing values of this parameters you have immediate impact on CBO so it is wisely to test effects of this parameters before activating them on production.

Two extremes:
Quote from "Effective Oracle by Design" book of Tom Kyte:

You should consider setting these to nondefault values for many systems, or at least testing the

two extremes:

o The default settings of OPTIMIZER_INDEX_CACHING = 0 and OPTIMIZER_INDEX_COST_ADJ = 100. These are
typically appropriate for many data warehouse/reporting systems.

o The settings of OPTIMIZER_INDEX_CACHING = 90 and OPTIMIZER_INDEX_COST_ADJ = 25. These are
typically appropriate for many transactional/OLTP systems.

REFERENCE:
Documentation: Optimizer_index_cost_adj

Read more →