Thursday, June 28, 2012

Purging Cursors From the Library Cache Using Full_hash_value

Introduction: Purging cursors from the library cache is a useful technique to keep handy for troubleshooting. Oracle has introduced a procedure call to do that in version 11 with backports to 10g. Besides Oracle documentation, this has been covered by several blogs already (including Kerry Osborne, Harald van Breederode, Martin Widlake, Martin Bach), Oracle support (note 457309.1 for example) and the actual package file in $ORACLE_HOME/rdbms/admin/dbmspool.sql

Most of the examples and discussions in the links above utilize with the following syntax:

SQL> exec sys.dbms_shared_pool.purge(‘&address, &hash_value’,'c’)


What's new in 11.2:

A new (overloaded) procedure in dbms_shared_pool.purge is available in 11.2 and allows to purge statements identified by thier full_hash_value of the statement. One of the advantages compared to the previous method is that the full_hash_value is a property of a given sql statement and does not depend on the memory address of the (parent) cursor. Note this has been tested in 11.2.0.3 64 bit for Linux.


Example:

myapp_user_SQL> select /*MYTEST*/ sysdate from dual; -- put test SQL statement that we want to flush in the following
admin_user_SQL> select a.FULL_HASH_VALUE from V$DB_OBJECT_CACHE a where name='select /*MYTEST*/ sysdate from dual';  
-- find full_hash_value to be used in the next step
-- in this example the full_hash_value is 98d0f8fcbddf4095175e36592011cc2c
admin_user_SQL> exec sys.dbms_shared_pool.purge(HASH=>'98d0f8fcbddf4095175e36592011cc2c',namespace=>0,heaps=>1) 


Additional info:

full_hash_value is a 128-bit MD5 hash of the sql statement. More details on full_hash_value at this link.
A few methods to find full_hash_value given different input are listed here below:
  • find full_hash_value from cache, query v$db_object_cache 
    • select a.FULL_HASH_VALUE from V$DB_OBJECT_CACHE a where name='select /*MYTEST*/ sysdate from dual';
  • find full_hash_value from hash_value
    • select full_hash_value from  v$db_object_cache where hash_value=538037292
  • find full_hash_value from sql_id
    • find hash_value from sql_id using DBMS_UTILITY.SQLID_TO_SQLHASH
    • select  full_hash_value from  v$db_object_cache where hash_value= DBMS_UTILITY.SQLID_TO_SQLHASH('1frjqb4h13m1c');
  • compute full_hash_value from SQL text
namespace=>0 means 'SQL  AREA' , which is the relevant namespace for cursors.

Conclusions:

We have discussed a method to purge cursors for the library cache that uses the full_hash_value of the cursor instead of the address and hash_value which is the more common approach (and the only one documented in previous versions). This method discussed here is available in 11.2.

Thursday, June 21, 2012

Kerberos Authentication and Proxy Users

Topic: a discussion on how to use Kerberos authentication  and of proxy users in Oracle. This aimed at providing an alternative to the classical use of username and password credential and to help ease the burden of DB credentials management.

Introduction: Kerberos authentication allows to connect to Oracle without specifying the username/password credentials. The authentication is done externally. Kerberos has been used by a large user community since many years (notably Windows Active Directory uses use Kerberos authentication).
Proxy authentication in Oracle, allows connection to a target DB username via another DB user (the proxy user). For example you can authorize a user with a development account to connect to the application owner account using his/her credentials (thus no need to expose the application user's password).

This post is about combining Kerberos and proxy authentication: you can provide a mean to connect to any given DB user via a Kerberos-authenticated user, i.e. without specifying the password at connection time.


Example of client-side configuration (Linux) 

  • These tests have been performed using Oracle server and client 11.2.0.3 for Linux  
    • See below for details of server-side configuration
  • Create oracle user and grant connection privileges: 
create user "LUCA@MYDOMAIN.COM" identified externally;
grant connect to  "LUCA@MYDOMAIN.COM" ;
...add tablespace config and other privileges if needed..
  • configure sqlnet.ora for the oracle client. This can be in $ORACLE_HOME/network/admin, $TNS_ADMIN or in $HOME/.sqlnet.ora depending on the scope of the configuration.
SQLNET.AUTHENTICATION_SERVICES=(ALL)            # easy way to includes KERBEROS5
SQLNET.KERBEROS5_CONF=/etc/krb5.conf            # need to have kerberos client configured
SQLNET.AUTHENTICATION_KERBEROS5_SERVICE=orasrv  #this needs to match DB server config
SQLNET.KERBEROS5_CONF_MIT=TRUE
  • Request kerberos pricipal for your user if not already present: kinit luca
    • At this point you'll need to put the password on the command line as asked
    • It's also possible to use the oracle utility okinit, in this case for our config we need to run okinit -e 23 luca. 
    • When using db link one need forwardable tickets (kinit -f)
  • Connect to the DB with kerberos credentials. In sqlplus use this syntax sqlplus /@MYDB
    • Show user will show LUCA@MYDOMAIN.COM
    • If you get instead ORA-12638: Credential retrieval failed means you need to troubleshoot. Unfortunately there are many causes for the error, staring with bugs and version incompatibilities (see also notes below).


Proxy users and Kerberos used together 

Suppose that we need to authorize the user luca@mydomain.com  to connect to production application. I would normally use: sqlplus myappuser/mysecretpass@MYDB. With Kerberos and proxy authentication, used together, we can do the following:
  • Authorize the user to use proxy authentication: 
    • alter user myappuser grant connect through "LUCA@MYDOMAIN.COM";
  • Check the configuration with select * from PROXY_USERS; 
  • Setup and test Kerberos authentication for MYDB, see steps above 
  • Connect to the production user with this method (Kerberos+proxy user]. 
    • The syntax in sqlplus is: sqlplus [myappuser]/@MYDB 
    • show user from sqlplus will show myappuser as result
    • With this method the password for myappuser has never been used. Only the password for the kerberos user  LUCA@MYDOMAIN.COM has been used when requesting the ticket with kinit
    • One can still connect to myappuser with the orginal username/pass credentials too, this is just an additional path to it

Notes on client-side configuration (Windows)

  • Kerberos authentication will work with the ticket granted by the domain at users logon
    • okinit, oklist etc are missing from instant client but are also not needed to make this work
    • do not use client 11.2.0.1 if possible. 
    • you need to logon as domain user
    • in alternative if you want to use this from a local account or usea different kerberos user, just run cmd.exe with run as and specify a domain user's credentials 
    • check with klist that you have the ticket for the principal "LUCA" in this example
  • Create or copy over krb5.conf from a Linux machine (for example from DB server)
  • Edit sqlnet.ora in %ORACLE_HOME%\network\admin (or %TNS_ADMIN%) adding the following:
SQLNET.AUTHENTICATION_SERVICES=(KERBEROS5)
SQLNET.KERBEROS5_CONF= ....put path here....\krb5.conf
SQLNET.KERBEROS5_CONF_MIT=TRUE
SQLNET.AUTHENTICATION_KERBEROS5_SERVICE=orasrv # match value on server
SQLNET.KERBEROS5_CC_NAME=OSMSFT:    # only needed in Windows
  • connect to the DB with kerberos credentials
    • same as the case of Linux above. 
    • In sqlplus use this syntax sqlplus /@MYDB 
  • This has been tested with a Windows 7 client and Oracle 11.2.0.3 instant client 32 bit

Notes on DB server configuration for kerberos authentication

This is described in Oracle documentation so I'll just put a few notes here.
  • Ask the kerberos administrator to add a new service principal. Best to use a short name, for example orasrv, as used in the examples above
  • Create the keytab file and on each DB server node(s) with correct permissions for the oracle user
    • for CERN installations the tool cern-get-keytab can be used:
    • sudo cern-get-keytab --service orasrv -k /etc/krb5.keytab.orasrv
    • sudo chown oracle:dba /etc/krb5.keytab.orasrv
  • Configure vi $ORACLE_HOME/network/admin/sqlnet.ora and add on all nodes 
    • note there are a few differences with client-only configuration discussed above
    • for RAC: edit sqlnet.ora in $ORACLE_HOME/network/admin, as opposed to $CRS_HOME/network/admin 
SQLNET.AUTHENTICATION_SERVICES=(ALL)
SQLNET.AUTHENTICATION_KERBEROS5_SERVICE=orasrv
SQLNET.KERBEROS5_KEYTAB=/etc/krb5.keytab.orasrv # see keytab generation step above
SQLNET.KERBEROS5_CONF=/etc/krb5.conf
SQLNET.KERBEROS5_CONF_MIT=TRUE


Notes:

Setting up Kerberos authentication requires just a few steps and is often quite simple. However there are many possible sources of issues that may need to be troubleshooted for a new installation. That ranges from bug in certain Oracle versions, incompatibilities with encryption levels, etc. I have tested with Oracle client 11.2.0.3 both on Linux and Windows 7 again Oracle server server on 11.2.0.3 (Linux 64 bit). This support note can be a useful starting point for troubleshooting if needed: Master Note For Kerberos Authentication [ID 1375853.1]
A (quite) different technique also aiming at reducing the need of hard-coded credentials is Secure External Password Store. This is described in oracle documentation and in the following support note: Using The Secure External Password Store [ID 340559.1]
Note added on licensing: a recent update to the Oracle licensing information states that "strong authentication services (Kerberos, PKI, and RADIUS) are no longer part of Oracle Advanced Security and are available in all licensed editions of all supported releases of the Oracle database."


Conclusions: 

We have discussed how to set up Kerberos authentication for Oracle users both as a standalone method and in conjunction with Proxy Authentication. These techniques can be of help to reduce the need of hard-coded credentials when accessing Oracle database services.

Monday, June 11, 2012

Hash Collisions in Oracle: SQL Signature and SQL_ID

Topic: Discussion and implementation of a method for finding hash collisions for sql_id and SQL signature in Oracle.

Introduction:

MD5 hashing is used by Oracle to compute sql_id and SQL signature (see also a previous blog post on the topic). Those hash values are normally used as if they were a unique representation of a given SQL statement. However collisions (2 different statements with the same hash value) can happen or, as it is the case of this post, will happen!

The underlying math is a short discussion of the birthday attack: Let's say you walk into a room an meet 30 people: shake hand with the first person you see and also disclose each other's the birthday. There is about 1 chance out 365 that that particular person has the same birthday as you. If you repeat this process with the rest of the 30 people in the room, chances of a 'positive event' increase but still stay below 10%. However when all the people in the room repeat the procedure of shaking hands and sharing birthday details, probabilities add up quickly (there are N(N-1)/2 different handshakes possible in a room of N people). The non-intuitive result is that it is likely that at least 2 people share a common birthday already in such a small group. See the link for the details.

The main point is that to find collisions by brute force on a hash function of n bits we don't need to generate O(2^n) hash values but rather the square root of that O(2^n/2). In particular this means that the complexity of finding hash collisions for 32-bit and 64-bit hash functions by brute force are down to numbers that are easily computable with current HW. sql_id and signatures are indeed 64-bit hashes, as discussed here, so let's give it a try!

Warm-up, collisions on hash_value:

The hash_value of a a given SQL statement (as shown in V$SQL.hash_value for example) is a 32-bit hash. Collisions can be found using about 100K random hashes. A simple algorithm using Oracle and PL/SQL is:
  • Take a couple of different SQL statements and append to them a randomly-generated string
  • Compute the MD5 hash and take the number of bytes that are needed (4 bytes in this case)
  • Insert the hashes in a table
  • Repeat ~100K times
  • When finished look in the output table for duplicates in the hash value
  • If duplicates are found, those are the hash_value collisions
The code can be found at this link. The execution takes just a few seconds and displays the collisions that have been found (results varies for each execution, normally 2-5 collisions are found for this size of search).

SQL> @hash_birthday_sql hashtab 10 4
SQL> @find_dup hashtab

-- these 2 statements are different but have the same hash_value (=3577689134)
SQL> select owner, index_name from dba_indexes where rownum<=9 --CTUUewnYYPJXFuFyAzcMtXTVNmPtNgAV;
SQL> select owner, table_name from dba_tables where rownum<=10 --ooXUUTNfekKkRZGlCJfiPlxKcoCfpDAh;

Scaling up to 64-bit hash: sql_id collisions

The same algorithm used for hash_value collisions can be used for sql_id, although we need to scale up the calculation: the hash is 8 byte long now and we need ~10 billion random hashes to find a few meaningful collisions. SQL> @hash_birthday_sql hashtab 500000 8 would take about 60 hours to do such calculation (mileage may vary). A faster way is to split the execution in smaller chunks and parallelize  the execution across multiple CPU and possibly RAC nodes. See the link here for an example on 2 RAC nodes and parallelism 10 each.

Results: the following two SQL statements are different but have the same sql_id (ayr58apvbz37z) and hash_value (1992264959).

SQL> select owner, index_name from dba_indexes where rownum<=9 --BaERRzEYqyYphBAvEbIrbYYDKkemLaib;
SQL> select owner, table_name from dba_tables where rownum<=10 --XhiidvehudXqDpCMZokNkScXlQiIUkUq;

--confirm this by running:
SQL> select sql_text from v$sql where sql_id='ayr58apvbz37z';

Another 64 bit hash, SQL signature collisions

A variation from the theme above is to calculate statements that have a SQL signature collision. The signature is used by SQL profiles, baselines and SQL patches. It is calculated in a similar but different way than sql_id, in particular SQL text is normalized before hashing (see this link for additional details). The base script is hash_birthday_signature.sql again parallel computation can be used to speed up the computation.

Results: the following two SQL statements are different but have the same signature (6284201623763853025), note sql_id values are different.

SQL> SELECT TABLE_NAME FROM USER_TABLES --JO7HWQAPNFYEALIOA3N5ODTR46INWY6N;
SQL> SELECT INDEX_NAME FROM USER_INDEXES --PAOZY8VWGDHDS9NICVREGTR22J6C24DQ;

--confirm this by running:
select sql_text from v$sql where force_matching_signature=6284201623763853025;

How does Oracle cope with collisions

In a few tests I have seen dbms_xplan throwing ORA-01422 when displaying plans for sql_id with collisions. There may be other packages/tools that make the assumption that sql_id values don't have collisions and they may throw errors.
These are a few more problems with SQL signature collisions. In particular a source of potential trouble is that one of the main (and common) underlying tables for  SQL plan management (baselines, profiles, patches) which stores the mappings of sql_text to signature, SYS.SQL$TEXT, has a unique index on signature. However we have seen that it is quite unlikely to have a signature collision just by pure chance (i.e. in the normal usage of the DB).

Conclusions:

This post reports on an exercise to compute collisions for sql_id and SQL signatures of Oracle statements using the Oracle database and PL/SQL. We have seen how some simple math, called birthday attack, can be of help and how an implementation of this in Oracle is quite easy up to hash length of 64 bit. We also report on the findings, notably collisions of sql_id and SQL signature.

Additional comments: a collision on full_hash_value (as reported in v$db_object_cache) could not be calculated with this method as it is a 128 bit hash and the brute force method would require resources out of a 'reasonable scale' . However, since 2005 there are methods known to find collisions for MD5 hashes on the full 128 bits that use weaknesses in the algorithm (that's why MD5 should not be used for security purposes any more). Those methods could be used to find full_hash_value collision.

PS: SQL and scripts mentioned in this article can be found following this link

Tuesday, June 5, 2012

SQL Signature, Text Normalization and MD5 Hash

Topic: A discussion on how Oracle computes SQL signature using MD5 hashing and on how SQL text is normalized before computing SQL signatures.

Introduction and warm-up:

SQL statements that are cached in the library cache are associated to a hash value, which is visible in various forms across a few V$ views. In 11gR2 for example: V$DB_OBJECT_CACHE.FULL_HASH_VALUE, V$SQL.SQL_ID, V$SQL.HASH_VALUE.

From the work of Tanel, Marcin and Slavik we learn that the full hash is an md5 hash in hexadecimal, sql_id is a base-32 representation of the trailing 8 bytes of the same md5 hash and finally the good old hash_value is a decimal representation of the trailing 4 bytes of the md5 hash.
Here below an example to illustrate how one can easily reproduce Oracle's hash values from md5 calculations (see also the blog entries mentioned above for more details):

--11gR2 hash from library cache, in 10g use x$kglob.kglnahsv  
SQL> select hash_value, to_char(hash_value,'xxxxxxxx') hex_hash_value, full_hash_value from GV$DB_OBJECT_CACHE where name='select 1 from dual';

HASH_VALUE  HEX_HASH_VALUE FULL_HASH_VALUE
----------- -------------- --------------------------------
2866845384  aae096c8       7d4dc9b423f0bcfb510272edaae096c8

The same  value can be calculated with md5_with_chr0.sql, a simple script based on DBMS_OBFUSCATION_TOOLKIT.MD5. Note chr(0) is added to the sql text before hashing.

SQL> @md5_with_chr0 'select 1 from dual'

CALCULATED_FULL_HASH
--------------------------------
7d4dc9b423f0bcfb510272edaae096c8 --> same value as full_hash_value above

SQL signature calculation and SQL text normalization

SQL signature is another type of hashing for SQL statements used by Oracle to support the features of plan management with SQL profiles, SQL patches, SQL plan baselines.


1) SQL statements are 'normalized'. Oracle performs transformations to the text before calculating the signature. Among others extra spaces are removed and case is ignored (see also oracle doc on V$SQL). An example here below to illustrate this: 2 SQL statements that differ only on case and additional whitespaces are shown to have the same SQL signature. Spoiler: normalization of more complex statements has some additional surprises, see below.

SQL> select DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE('select  1  from   dual') signature_with_space, DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE('SELECT 1 FROM DUAL') signature_normalized_sql from dual;

SIGNATURE_WITH_SPACE SIGNATURE_NORMALIZED_SQL
-------------------- ------------------------
12518811395313535686     12518811395313535686

2) Force matching is an additional option/feature of SQL signatures. It is used to match the text of SQL that uses literals. Oracle performs an additional transformation, that is literals are transformed into system-generated names for bind variables before hashing. An example below using literals (the value 1). The signature is converted in hexadecimal in this example, as we will use that for the following.

select to_char(DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE('SELECT 1 FROM DUAL'),'xxxxxxxxxxxxxxxx') exact_match_signature_hex,
       to_char(DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE('SELECT 1 FROM DUAL',force_match=>1),'xxxxxxxxxxxxxxxx') force_match_signature_hex from dual;

EXACT_MATCH_SIGNATURE_HEX FORCE_MATCH_SIGNATURE_HEX
------------------------- -------------------------
 adbbc0a2f3c68ac6         9289f992520d5a86


3) Computing SQL signatures directly with MD5. The script md5.sql  computes md5 hashes of the input (note it does not add a trailing chr(0)). We can reproduce the values obtained before and therefore confirm what is the transformation that Oracle does when calculating signatures.

SQL> @md5 'SELECT 1 FROM DUAL'

CALCULATED_FULL_HASH 
--------------------------------
d9f6df623a086c51adbbc0a2f3c68ac6  -> see exact_match in (2)above


SQL> @md5 'SELECT :"SYS_B_0" FROM DUAL'

CALCULATED_FULL_HASH
--------------------------------
a995b29240a442869289f992520d5a86  -> see force_match in (2) above

4) Additional investigations: when we have lists of columns or tables Oracle transforms ",", in " , " so actually in this case whitespaces may be added to the original statement and not removed as we have seen in point (1) above! An example here below:

SQL> select to_char(DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE('SELECT ID,ID FROM DUAL,DUAL',force_match=>1),'xxxxxxxxxxxxxxxx') force_match_signature_hex from dual;

FORCE_MATCH_SIGNATURE
---------------------
  65f0b8b3ef8a341

SQL @md5 'SELECT ID , ID FROM DUAL , DUAL'

CALCULATED_FULL_HASH
--------------------------------
4202d4045dbff1b4065f0b8b3ef8a341


Conclusions

The signature of SQL statements is calculated by Oracle using MD5 on the normalized SQL text. Normalization steps include removing extra white-space characters, converting the text to upper case. Additional normalization steps concern comma-separated list of objects: the item separator is  transformed into ' , ' (space, comma, space).
The MD5 hash calculated on the normalized SQL text is truncated to the last 8 bytes and is displayed in V$ views as a decimal number (SQL signature).
In the case of force matching signatures literals are additionally replaced with:"SYS_B_<n>" (where <n> is a decimal number, see example above), very much like the case when using cursor_sharing=force.
Note: a trailing chr(0) is added by Oracle when calculating hash_values/sql_id but not when calculating SQL signatures.

md5.sql and md5_with_chr0.sql scripts can be found at this link.

Monday, May 21, 2012

SQL Patch and Force Match

Discussion on how to create sql_patch with force_match=true in Oracle 11g and related topics.

SQL patches have recently saved the day for me in a production issue where a given SQL had suddenly changed execution plan causing IO overload (a full scan was done instead of index-based read for a high-load statement). 11g allows for a quick fix in such situations (as in, stop the fire and buy time to find a more stable solution): a set of hints can be added to a given query via the use of SQL Patch.
The official Oracle documentation has not many details on the topic (up to 11.2.0.3). Oracle's optimizer blog and Dominic Brooks have very good posts on the topic though.
I add here a few additional details that I have researched and found useful:


1) Recap (from the references listed above): how to create a SQL_PATCH from command line 

begin
 sys.dbms_sqldiag_internal.i_create_patch
  (sql_text  => '..put SQL here..',
   hint_text => '..put hints here..',
   name      => 'my patch name'); 
end;
/

2) What if I have a sql_id instead of the sql_text?

SQL> var c clob
SQL> exec select sql_fulltext into :c from v$sqlstats where sql_id='...' and rownum=1;

begin
 sys.dbms_sqldiag_internal.i_create_patch
  (sql_text  => :c,
   hint_text => '..put hints here..',
   name      => 'my patch name'); 
end;
/


3) What if I want to create a SQL patch with FORCE_MATCH = TRUE? (force match will additionally target all SQL statements that have the same text after normalizing literal values to bind variables). 

-- create sql patch
-- allows to set FORCE_MATCH to TRUE which is currently not possible with dbms_sqldiag_internal.i_create_patch (11.2.0.3)
-- run as sys
-- this is undocumented stuff, handle with care

DECLARE
    sql_text clob            := '....put sql here...';
    hints    varchar2(1000)  :='....put hints here...';
    description varchar2(100):='my patch description';
    name varchar2(100)       :='my patch name';
    output   varchar2(100);
    sqlpro_attr SYS.SQLPROF_ATTR;
  
BEGIN
    sqlpro_attr := SYS.SQLPROF_ATTR(hints);
    output      := SYS.DBMS_SQLTUNE_INTERNAL.I_CREATE_SQL_PROFILE(
      SQL_TEXT => sql_text,
      PROFILE_XML => DBMS_SMB_INTERNAL.VARR_TO_HINTS_XML(sqlpro_attr),
      NAME => name,       DESCRIPTION => description,     
      CATEGORY => 'DEFAULT',
      CREATOR => 'SYS',
      VALIDATE => TRUE,
      TYPE => 'PATCH',
      FORCE_MATCH => TRUE,
      IS_PATCH => TRUE);
    dbms_output.put_line(output);
  END;
/

4) Additional considerations:
What should I put as hints in the SQL PATCH? I would normally use the full outline content from an execution plan that I have tested and found OK. Mileage may vary. To print out the outline one can use:
select * from table(dbms_xplan.display('PLAN_TABLE',null,'OUTLINE'));

Drop and enable/disable SQL patches with: DBMS_SQLDIAG.DROP_SQL_PATCH and DBMS_SQLDIAG.ALTER_SQL_PATCH

Diagnostics:  dba_sql_patches. That view is based on tables shared with sql profiles and sql baselines. Underlying tables of interest for baselines, profiles and sql patches are: sys.sqlobj$data sys.sqlobj$auxdata, sys.sql$text, sys.sqlobj$
V$SQL.SQL_PATCH when not null reports the name of the sql patch that has been used to parse that particular child cursor.

Monday, May 14, 2012

V$EVENT_HISTOGRAM_METRIC

V$EVENT_HISTOGRAM_METRIC does not exist (at least up to 11.2.0.3) however it could be handy! The idea is combine the detailed information from event histograms and the ease of use of metric views. Here below an example of how this can be implemented with a sample script and a reference to the code of the script.

Example: Measure latency for single block reads for an OLTP database, as exposed by Oracle wait event interface as 'db file sequential read'. This is used to investigate a case of performance degradation where storage behaviour is involved.

Step 1: collect GV$EVENT_HISTOGRAM data in a period of normal activity using the script ehm.sql



Step 2: Plot data and analysis. Roughly 30 % of the reads are accounted as being competed in less than 1 ms. Those reads are being served from the SSD cache of the storage. A peak of latency is around 16 ms. We can interpret that as reads from physical disks (SATA disks at 7.2K rpm, that's why not very fast BTW)




Step 3: collect GV$EVENT_HISTOGRAM data during a period when applications report performance issues and plot data.

Analysis: Data measured in step 3 show that there are almost no blocks read from the SSD cache (that is there is no peak around the 1 ms measurement point) and that reads from physical IO have very high latency and definitely higher latency than normal (compare with graph above).
Note: This is the same case as discussed in a previous blog entry, see there for further details analisys of the investigations on what triggers this type of behaviour in the storage: "Of latency, skew and histograms 2/2"


The point I want to make: event histogram data gives valuable information for troubleshooting. In particular I have found useful the study of db file sequential read event. I is important to collect data samples over an interval of time of interest, as opposed to using raw data from gv$event_histogram that are cumulative since instance(s) startup.

This article describes the use of the script ehm.sql v1.0. A newer version has been released since. Both the old and new version can be found at this link.

Monday, May 7, 2012

Performance Metrics Views

Topic: GV$ views of the 'metrics family' and how they can help in tuning + links to scripts I use.

Oracle has plenty of instrumentation, statistics counters and wait event data are the bread and butter of Oracle monitoring and tuning.
However counters are typically incremented during the life of the instances/sessions, so delta values are often needed to make sense of data for analysis. AWR reports are a way to do that for instance-wide data.
A class of GV$ views that can be of help for faster/ 'online' monitoring are the V$ views that I call of the 'metric family'. Of those I find myself using often: gv$sysmetric, gv$eventmetric and gv$iofuncmetric
The great thing about metrics is that they report values accumulated over shorts period of times (15 and 60 sec are typical).  Effectively this provides the needed deltas.
Still one minor problem: a lot of data is reported by the metrics, more than what is needed normally. So a good filtering of the metrics of interest can be helpful.
Below a few examples of scripts that I have written and I use for this. (Scripts can be found here).

Examples:
sysmetric_details.sql reports on a dozen of metrics and lists values for instance (in RAC).



GV$IOFUNCMETRIC is new in 11gR2 and provides details on the type of IO the system is doing. An example below. This time iometric.sql aggregates over all instances of RAC.


Conclusions: gv$ views of the metric family provide a very useful set of tools for reactive performance analysis. They provide a quick view of key metrics, events consumed and IO done.
Limitations: views of the metric family don't provide a session-based view or a SQL-based view. They are often  more useful for finding the symptoms rather than the root causes of performance issues.

Monday, April 30, 2012

Of I/O Latency, Skew and Histograms 2/2

Case: This is part 2/2 of a performance investigation. In the previous part we have seen how the sudden increase of single block read latency would harm performance of the production database and how this would appear consistently when taking backups.

Drill down questions: what causes the high latency for single block reads during backup? Why do the sequential IO of the backup causes random reads to slow down? Are disks saturating? Is it an Oracle issue or more a storage issue? Finally, what can be done about it?

Oracle event histogram: Oracle instrumentation of wait events provides additional information in terms of histograms. Wait duration is divided in intervals and for each interval we can see how many wait events have happened. Historical data is collected and visible in AWR.

AWR data: Graph of data from DBA_HIST_EVENT_HISTOGRAM for the event db file sequential read are reported here below. In particular we can see that read of 1ms or less, that is reads served by the SSD cache of the storage, go to zero during the time backups are taken. Moreover wait of long duration (between 64 and 128 ms, which is a very long time for single block reads) show a peak at the same time.



Graph1: "Number of single block reads of 64 ms or more (that is very slow)" plotted as function of time. Large peaks are seen in correspondence of full backups (every 2 weeks), smaller peaks during daily backups.

 Graph2: "Number of single block read of 1 ms or less (that is blocks read from the SSD cache of the storage)" plotted as a function of time. Reading from the cache can be seen to go to zero during backups full backups (every two weeks, see also graph 1).

First conclusions and future work: IO becomes slow because backups effectively seem to flush the SSD cache. Also Very long response times are seen from single block IO. There is work to do on the storage side!
What about actions on the DB? Moving backup to the (active) Data Guard, can be of help, as it would effectively remove the workload source of contention.


Techniques and references: To analyze AWR data I have built a set of custom queries against dba_hist_* views and used them inside the excellent Perfsheet by Tanel Poder.
Moreover I'd like to reference James Morle's blog
This is the text of the query used, among others, to generate the graph above:

--event histogram with wait_count rate and time
select cast(sn.begin_interval_time as date) beg_time,
    eh.dbid,
    sn.instance_number,
    eh.event_name,
    eh.wait_time_milli,
    eh.wait_count,
    eh.wait_count - lag(eh.wait_count) over (partition by eh.dbid,eh.instance_number,eh.event_id,eh.wait_time_milli order by sn.snap_id nulls first) Delta_wait_count,
    extract(hour from END_INTERVAL_TIME-begin_interval_time)*3600
              + extract(minute from END_INTERVAL_TIME-begin_interval_time)* 60
              + extract(second from END_INTERVAL_TIME-begin_interval_time) DeltaT_sec,
    round((eh.wait_count - lag(eh.wait_count) over (partition by eh.dbid,eh.instance_number,eh.event_id,eh.wait_time_milli order by sn.snap_id nulls first)) /
          (extract(hour from END_INTERVAL_TIME-begin_interval_time)*3600
              + extract(minute from END_INTERVAL_TIME-begin_interval_time)* 60
              + extract(second from END_INTERVAL_TIME-begin_interval_time)),2 ) Rate_wait_count_per_bin
from dba_hist_event_histogram eh,
     dba_hist_snapshot sn
where
%FILTER%
and sn.snap_id = eh.snap_id
and sn.dbid = eh.dbid
and sn.instance_number = eh.instance_number
and sn.begin_interval_time between %FROM_DATE% and %TO_DATE%

Thursday, April 26, 2012

Of I/O Latency, Skew and Histograms 1/2


This is a performance investigation of Oracle DB and interaction with storage. 

Case: DB operations are slow during backup. The system is an OLTP-like workload, IO bound. Most of the reads are via indexes, typically single-block access, not much full scan.The system has still many free CPU cycles.  
First analysis: single block read times jump to very high values when backups start.
Tools: Use AWR data, to plot db file sequential read wait time over an interval of about 3 weeks. Large spikes can be seen during full DB backup. Spikes are also seen daily when incremental backup starts (see graph below)


Graph: average time spent on db file sequential read events aggregated per hour and plotted as as function of time. High and large spikes of IO latency can be seen during full backups. Smaller spikes during daily incremental backups.

Conclusions from first analysis: Users most important queries are IO latency-bound, latency jumps up during backups, therefore this explains the slowdown seen by the users.

Drill down: We want to understand why IO is slow during backup. Is it some sort of 'interference' of the sequential IO of the backup with random IO of the users? Is it an Oracle problem or a storage problem?
Main idea: use event histogram values reported by Oracle instrumentation to study skew on IO access time and find more about the root cause of the issue. Investigations: see part 2 of this blog entry.

Techniques and references: To analyze AWR data I have built a set of custom queries against dba_hist_* views and used them inside the excellent Perfsheet by Tanel Poder.
This is the text of the query used, among others, to generate the graph above:


-- system_event with rate and time
select cast(sn.begin_interval_time as date) beg_time,
    ss.dbid,
    sn.instance_number,
    ss.event_name,
    ss.wait_class,
    ss.total_waits,
    ss.time_waited_micro,
    ss.total_waits - lag(ss.total_waits) over (partition by ss.dbid,ss.instance_number,ss.event_id order by sn.snap_id nulls first) Delta_waits,
    ss.time_waited_micro - lag(ss.time_waited_micro) over (partition by ss.dbid,ss.instance_number,ss.event_id order by sn.snap_id nulls first) Delta_timewaited,
    extract(hour from END_INTERVAL_TIME-begin_interval_time)*3600
              + extract(minute from END_INTERVAL_TIME-begin_interval_time)* 60
              + extract(second from END_INTERVAL_TIME-begin_interval_time) DeltaT_sec,
    round((ss.total_waits - lag(ss.total_waits) over (partition by ss.dbid,ss.instance_number,ss.event_id order by sn.snap_id nulls first)) /
          (extract(hour from END_INTERVAL_TIME-begin_interval_time)*3600
              + extract(minute from END_INTERVAL_TIME-begin_interval_time)* 60
              + extract(second from END_INTERVAL_TIME-begin_interval_time)),2 ) Waits_per_sec,
    round((ss.time_waited_micro - lag(ss.time_waited_micro) over (partition by ss.dbid,ss.instance_number,ss.event_id order by sn.snap_id nulls first)) /
          (extract(hour from END_INTERVAL_TIME-begin_interval_time)*3600
              + extract(minute from END_INTERVAL_TIME-begin_interval_time)* 60
              + extract(second from END_INTERVAL_TIME-begin_interval_time)),2 ) Rate_timewaited,  -- time_waited_microsec/clock_time_sec
    round((ss.time_waited_micro - lag(ss.time_waited_micro) over (partition by ss.dbid,ss.instance_number,ss.event_id order by sn.snap_id nulls first)) /
           nullif(ss.total_waits - lag(ss.total_waits) over (partition by ss.dbid,ss.instance_number,ss.event_id order by sn.snap_id nulls first),0),2) Avg_wait_time_micro
from dba_hist_system_event ss,
     dba_hist_snapshot sn
where
%FILTER%
and sn.snap_id = ss.snap_id
and sn.dbid = ss.dbid
and sn.instance_number = ss.instance_number
and sn.begin_interval_time between %FROM_DATE% and %TO_DATE%

Wednesday, April 18, 2012

Uno

This is the first entry of this blog. Just to see if all works and to tune the layout. The blog will cover Oracle and databases. In particular tuning and internals.