22 October, 2014

StatsPack and AWR Reports -- Bits and Pieces -- 1

I am planning to put up a few posts on snippets from StatsPack and AWR reports.  This is my first post.
Note : Some figures / details may be slightly changed / masked to hide the real source.

Logical I/O and Change rates :
1.  From a 9.2 StatsPack Report:
Cache Sizes (end)
~~~~~~~~~~~~~~~~~
               Buffer Cache:                 Std Block Size:          4K
           Shared Pool Size:                     Log Buffer:      

Load Profile
~~~~~~~~~~~~                            Per Second      
                                   ---------------      
                  Redo size:             56,031.63               
              Logical reads:             68,286.24             
              Block changes:                314.88                
             Physical reads:                842.92                 
            Physical writes:                134.76                 

With a 4KB Block Size 68,286.24 Logical Reads translates to slightly over 266MB/second. Logical I/O is CPU-bound.  Database activity is Read-Intensive with a high rate of Reads relative to Writes.

2.  From an 11.2 AWR Report :
Cache Sizes
BeginEnd
Buffer Cache:
Std Block Size:16K
Shared Pool Size:
Log Buffer:
Load Profile
Per SecondPer TransactionPer ExecPer Call
DB Time(s):



DB CPU(s):



Redo size:1,593,612.1
Logical reads:51,872.5
Block changes:4,212.4
Physical reads:63.8
Physical writes:133.1

With a 16KB Block Size, 51,872.5 Logical Reads translates to slightly over 810MB/second.  This consumes CPU cycles.  However, here the number of Block Changes is noticeably high in this environment. This is also reflected in the high Redo rate -- slightly over 5,471MB/hour (Note : "Redo size" is in Bytes).


CPU Consumption :
1.  From a 9.2 StatsPack Report :
Statistic                                      Total     per Second    per Trans
--------------------------------- ------------------ -------------- ------------
CPU used by this session                                       37.5          2.1
CPU used when call started                                     37.6          2.1

This indicates 0.375seconds of CPU usage per second -- i.e. approximately 37.5% of 1 CPU (let's take this as an older non-multicore architecture). If the server has 4 CPUs, CPU consumption is 9.4%

2.  From an 11.2 AWR Report :

Instance Activity Stats

  • Ordered by statistic name
StatisticTotalper Secondper Trans
... deleted rows ....


... deleted rows ....


CPU used by this session46.85
CPU used when call started46.27

This indicates 0.468seconds of CPU usage per second -- i.e. approximately 46.8% of 1 Core.  This is also reflected in the Load Profile section :
Load Profile
Per SecondPer TransactionPer ExecPer Call
DB Time(s):



DB CPU(s):0.50.10.000.00

How many CPUs does this machine have ?  AWR reports this :
Host NamePlatformCPUsCoresSocketsMemory (GB)
Linux x86 64-bit16162

That means we are using less than half of 1 of 16 cores !  This translates to CPU consumption of 3.125%  The server has too many CPU cores !

18 October, 2014

Bandwidth and Latency

Here is, verbatim, an article I posted on Linked-In yesterday  [For other posts on Linked-In, view my Linked-In profile] :

Imagine an 8-lane highway. Now imagine a 4-lane highway. Which has the greater bandwidth ?
Imagine your organisation sends its employees on a wekend "retreat" by bus. You have the choice of two locations, one that is 200kilometres away and the other is 80kilometres away. Assume that buses travel at a constant speed of 80kmph. Which resort will your employees get to faster ?
The first question is about bandwidth. The second is about latency.
(Why should I assume a fixed speed for the buses ? Because, I can assume a fixed speed at which electrons transfer over a wire or photons over a light channel).
Expand the question further. What if the organisation needs to send 32 employees in a 40-seater bus. Does it matter that the bus can travel on an 8-lane highway versus a 4-lane highway (assuming minimal other traffic on the highways at that time) ?
Too often, naive "architects" do not differentiate between the two. If my organisation needs to configure a standby (DR) location for the key databases and has a choice of two locations but varying types of network services, it should consider *both* bandwidth and latency. If the volume of redo is 1000MBytes per minute and this, factoring overheads for packetizing the "data", translates to 167Mbits per second, should I just go ahead and buy bandwidth of 200Mbits per second ? If the two sites have two different network services providers offering different bandwidths, should I simply locate at the site with the greater bandwidth ? What if the time it takes to synchronously write my data to site "A" is 4ms and the time to site "B" is 8ms ? Should I not factor the latency ? (I am assuming that the "write to disk" speed of hardware at either site is the same -- i.e. the hardware is the same). I can then add the complications of network routers and switches that add to the latency. Software configurations, flow-control mechanisms, QoS definitions and hardware configuration can also impact bandwidth and latency in different ways.
Now, extend this to data transfers ("output" or "results") from a database server to an application server or end-user. If the existing link is 100Mbps and is upgraded to 1Gbps, the time to "report" 100 rows is unlikely to change as this time is a function of the latency. However, if the number of concurrent users grows from 10 to 500, the bandwidth requirement may increase and yet each user may still have the same "wait" time to see his results (assuming that there are no server hardware constraints returning results for 500 users).
On the flip side, consider ETL servers loading data into a database. Latency is as important as bandwidth. An ETL scheme that does "row-by-row" loads relies on latency, not bandwidth. Increasing bandwidth doesn't help such a scheme.
Think about the two.

04 October, 2014

11g Adaptive Cursor Sharing --- does it work only for SELECT statements ? Using the BIND_AWARE Hint for DML

Test run in 11.2.0.2

UPDATE 07-Oct-14 :  I have been able to get the DML statement also to demonstrate Adaptive Cursor Sharing with the "BIND_AWARE" hint as suggested by Stefan Koehler and Dominic Brooks.

Some of you may be familiar with Adaptive Cursor Sharing.

This is an 11g improvement over the "bind peek once and execute repeatedly without evaluating the true cost of execution" behaviour that we see in 10g.  Thus, if the predicate is skewed and the bind value is changed, 10g does not "re-peek" and re-evaluate the execution plan. 11g doesn't "re-peek" at the first execution with  new bind but if it finds the true cardinality returned by the execution at signficant variance, it decides to "re-peek" at a subsequent execution.  This behaviour is determined by the new attributes "IS_BIND_SENSITIVE" and "IS_BIND_AWARE" for the SQL cursor.

If a column is highly skewed, as determined by the presence of  Histogram, the Optimizer, when parsing an SQL with a bind against the column as a predicate, marks the SQL as BIND_SENSITIVE. If two executions with two different bind values return very different counts of rows for the predicate, the SQL is marked BIND_AWARE.  The Optimizer "re-peeks" the bind and generates a new Child Cursor that is marked as BIND_AWARE.

Here is a demo.


SQL> -- create and populate table
SQL> drop table demo_ACS purge;

Table dropped.

SQL>
SQL> create table demo_ACS
  2  as
  3  select * from dba_objects
  4  where 1=2
  5  /

Table created.

SQL>
SQL> -- populate the table
SQL> insert /*+ APPEND */ into demo_ACS
  2  select * from dba_objects
  3  /

75043 rows created.

SQL>
SQL> -- create index on single column
SQL> create index demo_ACS_ndx
  2  on demo_ACS (owner) nologging
  3  /

Index created.

SQL>
SQL> select count(distinct(owner))
  2  from demo_ACS
  3  /

COUNT(DISTINCT(OWNER))
----------------------
                    42

SQL>
SQL> select owner, count(*)
  2  from demo_ACS
  3  where owner in ('HEMANT','SYS')
  4  group by owner
  5  /

OWNER      COUNT(*)
-------- ----------
HEMANT           55
SYS           31165

SQL>
SQL> -- create a histogram on the OWNER column
SQL> exec dbms_stats.gather_table_stats('','DEMO_ACS',estimate_percent=>100,method_opt=>'FOR COLUMNS OWNER SIZE 250');

PL/SQL procedure successfully completed.

SQL> select column_name, histogram, num_distinct, num_buckets
  2  from user_tab_columns
  3  where table_name = 'DEMO_ACS'
  4  and column_name = 'OWNER'
  5  /

COLUMN_NAME                    HISTOGRAM       NUM_DISTINCT NUM_BUCKETS
------------------------------ --------------- ------------ -----------
OWNER                          FREQUENCY                 42          42

SQL>

So, I now have a table that has very different row counts for 'HEMANT' and 'SYS'. The data is skewed. The Execution Plan for queries on 'HEMANT' would not be optimal for queries on 'SYS'.

Let's see a query executing for 'HEMANT'.

SQL> -- define bind variable
SQL> variable target_owner varchar2(30);
SQL>
SQL> -- setup first SQL for 'HEMANT'
SQL> exec :target_owner := 'HEMANT';

PL/SQL procedure successfully completed.

SQL>
SQL> -- run SQL
SQL> select owner, object_name
  2  from demo_ACS
  3  where owner = :target_owner
  4  /

OWNER    OBJECT_NAME
-------- ------------------------------
.....
.....

55 rows selected.

SQL>
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  1820xq3ggh6p6, child number 0
-------------------------------------
select owner, object_name from demo_ACS where owner = :target_owner

Plan hash value: 805812326

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       |     3 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| DEMO_ACS     |    55 |  3960 |     3   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | DEMO_ACS_NDX |    55 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

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

   2 - access("OWNER"=:TARGET_OWNER)


19 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = '1820xq3ggh6p6'
  4  order by child_number
  5  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
1820xq3ggh6p6            0       805812326 Y N          1             55

SQL> commit;

Commit complete.

SQL>

We see one execution of the SQL Cursor with an Index Range Scan and Plan_Hash_Value 805812326. The SQL is marked BIND_SENSITIVE because of the presence of a Histogram indicating skew.

Now, let's change the bind value from 'HEMANT' to 'SYS' and re-execute exactly the same query.

SQL> -- setup second SQL for 'SYS'
SQL> exec :target_owner := 'SYS';

PL/SQL procedure successfully completed.

SQL>
SQL> -- run SQL
SQL> select owner, object_name
  2  from demo_ACS
  3  where owner = :target_owner
  4  /

OWNER    OBJECT_NAME
-------- ------------------------------
.....
.....

31165 rows selected.

SQL>
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  1820xq3ggh6p6, child number 0
-------------------------------------
select owner, object_name from demo_ACS where owner = :target_owner

Plan hash value: 805812326

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       |     3 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| DEMO_ACS     |    55 |  3960 |     3   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | DEMO_ACS_NDX |    55 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

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

   2 - access("OWNER"=:TARGET_OWNER)


19 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = '1820xq3ggh6p6'
  4  order by child_number
  5  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
1820xq3ggh6p6            0       805812326 Y N          2          31220

SQL> commit;

Commit complete.

SQL>

This time, for 31,165 rows (instead of 55 rows), Oracle has used the same Execution Plan -- the same Plan_Hash_Value and the same expected cardinality of 55 rows. However, the Optimizer is now "aware" that the 55 row Execution Plan actually returned 31.165 rows.

The next execution will see a re-parse because of this awareness.

SQL> -- rerun second SQL
SQL> select owner, object_name
  2  from demo_ACS
  3  where owner = :target_owner
  4  /

OWNER    OBJECT_NAME
-------- ------------------------------
.....
.....

31165 rows selected.

SQL>
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  1820xq3ggh6p6, child number 1
-------------------------------------
select owner, object_name from demo_ACS where owner = :target_owner

Plan hash value: 1893049797

------------------------------------------------------------------------------
| Id  | Operation         | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |          |       |       |   299 (100)|          |
|*  1 |  TABLE ACCESS FULL| DEMO_ACS | 31165 |  2191K|   299   (1)| 00:00:04 |
------------------------------------------------------------------------------

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

   1 - filter("OWNER"=:TARGET_OWNER)


18 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = '1820xq3ggh6p6'
  4  order by child_number
  5  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
1820xq3ggh6p6            0       805812326 Y N          2          31220
1820xq3ggh6p6            1      1893049797 Y Y          1          31165

SQL> commit;

Commit complete.

SQL>

Aha ! This time we have a new Plan_Hash_Value (1893049797) for a Full Table Scan, being represented as a new Child Cursor (Child 1) that is now BIND_AWARE.






Now, here's the catch I see.  If I change the "SELECT ....." statement to an "INSERT .... SELECT ....", I do NOT see this behaviour.  I do NOT see the cursor becoming BIND_AWARE as a new Child Cursor.
Thus, the 3rd pass of an "INSERT ..... SELECT ..... " being the second pass with the Bind Value 'SYS' is correctly BIND_SENSITIVE but not BIND_AWARE.  This is what it shows :


SQL> -- rerun second SQL
SQL> insert into target_tbl
  2  (
  3  select owner, object_name
  4  from demo_ACS
  5  where owner = :target_owner
  6  )
  7  /

31165 rows created.

SQL>
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  cqyhjz5a5xyu4, child number 0
-------------------------------------
insert into target_tbl ( select owner, object_name from demo_ACS where
owner = :target_owner )

Plan hash value: 805812326

---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | INSERT STATEMENT             |              |       |       |     3 (100)|          |
|   1 |  LOAD TABLE CONVENTIONAL     |              |       |       |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID| DEMO_ACS     |    55 |  3960 |     3   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | DEMO_ACS_NDX |    55 |       |     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------

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

   3 - access("OWNER"=:TARGET_OWNER)


21 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = 'cqyhjz5a5xyu4'
  4  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
cqyhjz5a5xyu4            0       805812326 Y N          3          62385

SQL> commit;

Commit complete.

SQL>

Three executions -- one with 'HEMANT' and the second and third with 'SYS' as the Bind Value -- all use the *same* Execution Plan.

So, does this mean that I cannot expect ACS for DML ?


UPDATE 07-Oct-14 :  I have been able to get the DML statement also to demonstrate Adaptive Cursor Sharing with the "BIND_AWARE" hint as suggested by Stefan Koehler and Dominic Brooks.

SQL> -- run SQL
SQL> insert /*+ BIND_AWARE */ into target_tbl
  2  (
  3  select owner, object_name
  4  from demo_ACS
  5  where owner = :target_owner
  6  )
  7  /
  
55 rows created.
  
SQL> 
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  0cca9xusptauj, child number 0
-------------------------------------
insert /*+ BIND_AWARE */ into target_tbl ( select owner, object_name
from demo_ACS where owner = :target_owner )
  
Plan hash value: 805812326
  
---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | INSERT STATEMENT             |              |       |       |     3 (100)|          |
|   1 |  LOAD TABLE CONVENTIONAL     |              |       |       |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID| DEMO_ACS     |    55 |  3960 |     3   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | DEMO_ACS_NDX |    55 |       |     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------

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

   3 - access("OWNER"=:TARGET_OWNER)


21 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = '0cca9xusptauj'
  4  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
0cca9xusptauj            0       805812326 Y Y          1             55

SQL> commit;

Commit complete.

SQL>
SQL> -- setup second SQL for 'SYS'
SQL> exec :target_owner := 'SYS';

PL/SQL procedure successfully completed.

SQL>
SQL> -- run SQL
SQL> insert /*+ BIND_AWARE */ into target_tbl
  2  (
  3  select owner, object_name
  4  from demo_ACS
  5  where owner = :target_owner
  6  )
  7  /

31165 rows created.

SQL>
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  0cca9xusptauj, child number 1
-------------------------------------
insert /*+ BIND_AWARE */ into target_tbl ( select owner, object_name
from demo_ACS where owner = :target_owner )

Plan hash value: 1893049797

-------------------------------------------------------------------------------------
| Id  | Operation                | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | INSERT STATEMENT         |          |       |       |   299 (100)|          |
|   1 |  LOAD TABLE CONVENTIONAL |          |       |       |            |          |
|*  2 |   TABLE ACCESS FULL      | DEMO_ACS | 31165 |  2191K|   299   (1)| 00:00:04 |
-------------------------------------------------------------------------------------

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

   2 - filter("OWNER"=:TARGET_OWNER)


20 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = '0cca9xusptauj'
  4  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
0cca9xusptauj            0       805812326 Y Y          1             55
0cca9xusptauj            1      1893049797 Y Y          1          31165

SQL> commit;

Commit complete.

SQL>
SQL> -- rerun second SQL
SQL> insert /*+ BIND_AWARE */ into target_tbl
  2  (
  3  select owner, object_name
  4  from demo_ACS
  5  where owner = :target_owner
  6  )
  7  /

31165 rows created.

SQL>
SQL> -- get execution plan
SQL> select * from table(dbms_xplan.display_cursor);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  0cca9xusptauj, child number 1
-------------------------------------
insert /*+ BIND_AWARE */ into target_tbl ( select owner, object_name
from demo_ACS where owner = :target_owner )

Plan hash value: 1893049797

-------------------------------------------------------------------------------------
| Id  | Operation                | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | INSERT STATEMENT         |          |       |       |   299 (100)|          |
|   1 |  LOAD TABLE CONVENTIONAL |          |       |       |            |          |
|*  2 |   TABLE ACCESS FULL      | DEMO_ACS | 31165 |  2191K|   299   (1)| 00:00:04 |
-------------------------------------------------------------------------------------

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

   2 - filter("OWNER"=:TARGET_OWNER)


20 rows selected.

SQL>
SQL> -- get SQL query info
SQL> select sql_id, child_number, plan_hash_value, is_bind_sensitive, is_bind_aware, executions, rows_processed
  2  from v$SQL
  3  where sql_id = '0cca9xusptauj'
  4  /

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE I I EXECUTIONS ROWS_PROCESSED
------------- ------------ --------------- - - ---------- --------------
0cca9xusptauj            0       805812326 Y Y          1             55
0cca9xusptauj            1      1893049797 Y Y          2          62330

SQL> commit;

Commit complete.

SQL>

However, there is a noticeable difference.  With the BIND_AWARE Hint, the SQL is Bind Aware right from the first execution (for :target_owner='HEMANT').  So, even at the second execution (for the first run of :target_owner='SYS'), it re-peeks and generates a new Execution Plan (the Full Table Scan) for a new Child (Child 1).
.
.
.