Quiz – Whose Answer is it Anyway? | Charles Hooper's Oracle Notes

Histograms – What is Wrong with this Quote?

4 07 2012

July 4, 2012

It has been several months since I posted my review of the first half of the “Oracle Database 11gR2 Performance Tuning Cookbook” book. I had planned to post the review for the second half of the book a couple of weeks later, however four months have passed by since that time, and the second half of the review has yet to materialize. Someone recently left the following comment attached to one of my reviews on Amazon:

“This is the most comprehensive feedback I have ever read!!”

I appeciate the comment. Keep in mind that particular review was only roughly 9.5 typewritten pages in length; it takes a lot of time to put together an 18, 24, or 35 typewritten page review that is just as comprehensive as the one that elicited the above comment.

On to the topic of this article…

While reading the “Oracle Database 11gR2 Performance Tuning Cookbook” book, I noticed an interesting set of statements about the use of histograms (bolded sections appeared bolded in the book):

“Histograms are useful only on indexed columns containing skewed values, because they help the optimizer to choose whether to use the index or not to access values. Obviously, if the frequency for a specific value is very high, using the index won’t be the best choice….”

“Don’t use histograms in situations where:

The column is not used in the WHERE clauses of the queries

The data in the column is uniformly distributed

Bind variables are used when comparing against the column”

What, if anything, is wrong with the above quote from the book? If possible, provide test cases to support or refute the above quote from the book (see the tips at the bottom of the blue section at the right of this blog page regarding how to post code sections).

The point of blog articles like this one is not to insult authors who have spent thousands of hours carefully constructing an accurate and helpful book, but instead to suggest that readers investigate when something stated does not exactly match what one believes to be true. It could be that the author “took a long walk down a short pier”, or that the author is revealing accurate information which simply cannot be found through other resources (and may in the process be directly contradicting information sources you have used in the past). If you do not investigate in such cases, you may lose an important opportunity to learn something that could prove to be extremely valuable.

Comments : 10 Comments »

Categories : Histogram, Quiz - Whose Answer is it Anyway?

Temporary Tablespace Storage Parameters – What is Wrong with this Quote

22 04 2012

April 22, 2012 (Modified April 24, 2012)

I had intended to finish assembling the second half of the “Oracle Database 11gR2 Performance Tuning Cookbook” book review, however my free time that may be dedicated to book reviews has been a bit limited lately (I have a review of another book started, but left untouched for the last three months). On a side note, I am a little shocked that none of the 21 errata reports that I filed for the first 88 pages of the book made it onto the publisher’s website, but maybe that is not too uncommon (the same has happened for at least one Apress book).

I encountered an interesting quote on page 252 of the “Oracle Database 11gR2 Performance Tuning Cookbook” that I thought I would share with readers:

“The PCTINCREASE parameter cannot be specified when we use the AUTOALLOCATE option for the tablespace. We can have different tablespaces for each database user and we can query the dynamic performance view V$SORT_USAGE to retrieve the details about the active disk sorts occurring in the instance.

We can obtain better performance by striping the temporary tablespace using multiple disks. Please note that – due to their nature – temporary tablespaces are not affected by backup and restore operations.”

If you own the book, start on page 251 and read through the end of page 252. – there are a couple of additional interesting sentences in this section of the book

What, if anything, is wrong with the above quote from the book? For those readers that need some assistance with this task, the Oracle Database 11.2 documentation might be helpful.

—

(Added April 24, 2012, my book review notes for the four quoted sentences, plus one of the preceding sentences)

The book’s discussion of defining the INITIAL and NEXT storage parameters for temporary tablespaces as a multiple of the SORT_AREA_SIZE parameter seems to be out of place in an Oracle Database 11g R2 performance tuning book – dictionary managed tablespaces were deprecated with the release of Oracle Database 9.2, and the effect of these parameters is different in locally managed tablespaces (page 252).
The book states, “The PCTINCREASE parameter cannot be specified when we use the AUTOALLOCATE option for the tablespace.” This statement appears to be incorrect – the Oracle Database documentation states that a specified value for PCTINCREASE will be ignored when creating an AUTOALLOCATE tablespace (page 252).
The book states, “We can have different tablespaces for each user and we can query the dynamic performance view V$SORT_USAGE to retrieve the details about the active disk sorts occurring in the instance.” This statement is a bit confusing, so it is probably best to break the sentence into two separate logical sentences for analysis. The first half of the statement seems to suggest that a separate temp tablespace should (or could) be created for each user – I am not sure that this is the author’s intended interpretation; the default temporary tablespace may be set at the user level so that not all users are required to use the same (default) temporary tablespace. For the second logical sentence, the V$SORT_USAGE performance view was deprecated with the release of Oracle Database 9.2, replaced with V$TEMPSEG_USAGE. In Oracle Database 11.2 (the version mentioned on the book’s front cover), the V$SORT_USAGE view is based on the GV$SORT_USAGE view which selects from X$KTSSO (confirm by issuing SELECT VIEW_DEFINITION FROM V$FIXED_VIEW_DEFINITION WHERE VIEW_NAME=’GV$SORT_USAGE’;). The GV$SORT_USAGE view definition, which is pointed to by both the V$SORT_USAGE and V$TEMPSEG_USAGE synonyms, indicates that the SEGTYPE column values may be one of SORT, HASH, DATA, INDEX, LOB_ DATA, LOB_INDEX , or UNDEFINED. The potential values of the SEGTYPE column suggests that the view potentially shows a variety of activity in addition to what the book mentions (the WHERE clause should be adapted to restrict the rows returned from this view, so that the results are consistent with this chapter’s contents). The V$SORT_USAGE view also shows entries for aborted SQL statements, for instance when Ctrl-C is pressed in SQL*Plus and another SQL statement has not been executed by the session (page 252).
The book states, “Please note that – due to their nature – temporary tablespaces are not affected by backup and restore operations.” This is a vague statement at best, and the accuracy of the statement depends in part on the type of backup performed (online or offline, user-managed or RMAN hot backup, etc.). An online RMAN backup will not back up the tempfiles of locally managed temporary tablespaces; however, when those backed up databases are restored and recovered, Oracle Database 10.2 and later will recreate the temporary tablespace tempfiles when the database is opened (page 252).

Comments : 11 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Repeat After Me: NULL Values are Not Stored in Indexes?

28 02 2012

February 28, 2012

I do not always get as much benefit from the books that I read as the books’ authors probably intended, although the contents of books, whether right or wrong, sometimes help me remember nearly forgotten facts. Some of the books, for instance “Pro Oracle SQL” describe how to use b*tree indexes to locate rows with NULL values in a column. The book “Expert Oracle Database Architecture: Oracle Database Programming 9i, 10g, and 11g Techniques and Solutions, Second Edition” also shows several techniques for utilizing b*tree indexes to locate rows with NULL values in a column. Richard Foote’s blog also has at least one article that describes how to use b*tree indexes to locate NULL values in a column.

So, what headed me down the path of NULL Values are Not Stored in Indexes? I read the following sentence in the book “Oracle Database 11gR2 Performance Tuning Cookbook” on page 177:

“NULL values are not stored in indexes, so when we query for records with a NULL value in field X, even if the X column is indexed, the index will not be used.”

I can’t help but feel that I have seen very similar statements in the past. The Oracle Database documentation, at least from 8.1 through 11.1 included the following quote:

“The query must be guaranteed not to need any NULL values from the indexed expression, because NULL values are not stored in indexes.”

But where else have I seen that message? A Google search for: oracle NULL values are not stored in indexes found a couple of places where the message is repeated.

“Oracle Database 11g: The Complete Reference” (I read the 9i version of this book years ago):

“NULL values are not stored in indexes. Therefore, the following query will not use an index; there is no way the index could help to resolve the query:”
select Title
  from BOOKSHELF
 where CategoryName is null;

“Oracle 9i Performance Tuning Tips & Techniques” page 39 (I quickly paged through the 10g book in a book store once, and read the sample chapter on Statspack reports):

“Using IS NULL or IS NOT NULL will also suppress index use because the value of NULL is undefined.”

“Oracle Data Warehouse Tuning for 10g” page 51 (I have not had the opportunity to read this book):

“For a BTree index, NULL values are not included in the BTree structure and, thus, not even accessible through the index.”

“Expert Indexing in Oracle Database 11g” page 159 (any problems here – I think that I have a test case somewhere that suggests that the second column should be a number, I thought about buying this book):

“If all index columns are NULL, Oracle Database doesn’t include rows into an index. However, you can actually index NULL values by simply adding another column to the index, like so:
SQL> create index with_null on employees(nullable_column, '1');

—

So, what is my review comment for the Cookbook?

The book states, “NULL values are not stored in indexes, so when we query for records with a NULL value in field X, even if the X column is indexed, the index will not be used.” The book’s description is incomplete. NULL values are not stored in single column b*tree indexes. There are at least four methods to work around this issue and allow indexes to be used to identify rows with a NULL value in the indexed column:

Define a composite index with at least one other column that has a NOT NULL constraint – ideally, the column in which the NULL values might appear would be the leading column in the composite index.

Define a composite index with a numeric constant (such as 1) as the second column in the composite index.

Bitmap indexes always store NULL values – if appropriate (column experiences few updates, deletes, inserts, and an Enterprise Edition database), create a bitmap index for the column.

If the number of NULL values in a column will be relatively small (compared to the number of rows in the table), and the original SQL statement may be modified, create a function based index that converts NULL values to 1 and non-NULL values to NULL:

DECODE(C3,NULL,1)

(CASE WHEN C3 IS NULL THEN 1 ELSE NULL END)

(NVL2(C3,NULL,1))

Let’s build a little test case to demonstrate. First, a table is created with 1,000,000 rows, two indexes are created, and then statistics are gathered with histograms generated for all indexed columns:

CREATE TABLE T2 (
  C1 NUMBER NOT NULL,
  C2 VARCHAR2(15) NOT NULL,
  C3 DATE,
  C4 VARCHAR2(255));

INSERT INTO T2
SELECT
  ROWNUM C1,
  RPAD(CHR(MOD(ROWNUM-1,26)+65),15,'0') C2,
  DECODE(MOD(ROWNUM,100),0,NULL,SYSDATE+ROWNUM/10000) C3,
  RPAD('A',255,'A') C4
FROM
  DUAL
CONNECT BY
  LEVEL<=1000000;

COMMIT;

CREATE INDEX IND_T2_C3_C2 ON T2(C3,C2);
CREATE INDEX IND_T2_C3_C ON T2(C3,1);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T2',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR ALL INDEXED COLUMNS SIZE 254')

In the above table, 1% of the rows will have a NULL value in column C3.

Let’s try the first test to see if one of the above two indexes may be used to locate the NULL values in column C3:

SELECT
  C1,
  C2,
  C3
FROM
  T2
WHERE
  C2='D00000000000000'
  AND C3 IS NULL;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  3sjqqpjradbgz, child number 0
-------------------------------------
SELECT   C1,   C2,   C3 FROM   T2 WHERE   C2='D00000000000000'   AND C3
IS NULL

Plan hash value: 895813321

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       |   389 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| T2           |   385 | 14245 |   389   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | IND_T2_C3_C2 |   385 |       |     4   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C3" IS NULL AND "C2"='D00000000000000')
       filter("C2"='D00000000000000')

Well, it appears that the composite index on columns C3 and C2 might have helped quickly locate the rows with NULL values in column C3 (we just tested point #1 above). Let’s drop that index and try again:

DROP INDEX IND_T2_C3_C2;

SELECT
  C1,
  C2,
  C3
FROM
  T2
WHERE
  C2='D00000000000000'
  AND C3 IS NULL;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  3sjqqpjradbgz, child number 0
-------------------------------------
SELECT   C1,   C2,   C3 FROM   T2 WHERE   C2='D00000000000000'   AND C3
IS NULL

Plan hash value: 1053304445

-------------------------------------------------------------------------------------------
| Id  | Operation                   | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |             |       |       |   550 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID| T2          |   385 | 14245 |   550   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | IND_T2_C3_C | 10000 |       |    33   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"='D00000000000000')
   2 - access("C3" IS NULL)

This time we cannot simply state that “NULL Values are Not Stored in Indexes”. The Predicate Information section of the execution plan shows access(“C3” IS NULL) (we just tested point #2 above).

Let’s drop the index and try something else:

DROP INDEX IND_T2_C3_C;

CREATE BITMAP INDEX IND_T2_C3_BIN ON T2(C3);

SELECT
  C1,
  C2,
  C3
FROM
  T2
WHERE
  C2='D00000000000000'
  AND C3 IS NULL;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  3sjqqpjradbgz, child number 0
-------------------------------------
SELECT   C1,   C2,   C3 FROM   T2 WHERE   C2='D00000000000000'   AND C3
IS NULL

Plan hash value: 1153509852

----------------------------------------------------------------------------------------------
| Id  | Operation                    | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |               |       |       |  1954 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID | T2            |   385 | 14245 |  1954   (0)| 00:00:01 |
|   2 |   BITMAP CONVERSION TO ROWIDS|               |       |       |            |          |
|*  3 |    BITMAP INDEX SINGLE VALUE | IND_T2_C3_BIN |       |       |            |          |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"='D00000000000000')
   3 - access("C3" IS NULL)

Once again, we found that we cannot simply state that “NULL Values are Not Stored in Indexes”. The Predicate Information section of the execution plan shows access(“C3” IS NULL) (we just tested point #3 above).

Let’s drop the index and try just indexing the NULLs (sub-point 1 of point #4 above):

DROP INDEX IND_T2_C3_BIN;

CREATE INDEX IND_T2_C3_FN ON T2 DECODE(C3,NULL,1);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T2',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR ALL HIDDEN COLUMNS SIZE 254 FOR ALL INDEXED COLUMNS SIZE 254',NO_INVALIDATE=>FALSE)

SELECT /*+ INDEX(T2) */
  C1,
  C2,
  C3,
  NVL2(C3,NULL,1) C4
FROM
  T2
WHERE
  C2='D00000000000000'
  AND DECODE(C3,NULL,1)=1;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  8psj7gcwcn72m, child number 0
-------------------------------------
SELECT /*+ INDEX(T2) */   C1,   C2,   C3,   NVL2(C3,NULL,1) C4 FROM
T2 WHERE   C2='D00000000000000'   AND DECODE(C3,NULL,1)=1

Plan hash value: 2303772603

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       |  3752 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID| T2           |   385 | 14245 |  3752   (1)| 00:00:01 |
|*  2 |   INDEX FULL SCAN           | IND_T2_C3_FN | 10000 |       |  3234   (2)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"='D00000000000000')
   2 - filter(DECODE(INTERNAL_FUNCTION("C3"),NULL,1)=1)

The index that we created was used. Once again, we found that we cannot simply state that “NULL Values are Not Stored in Indexes”.

Let’s drop the index and try just indexing the NULLs (sub-point 2 of point #4 above):

DROP INDEX IND_T2_C3_FN;

CREATE INDEX IND_T2_C3_FN ON T2 (CASE WHEN C3 IS NULL THEN 1 ELSE NULL END);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T2',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR ALL HIDDEN COLUMNS SIZE 254 FOR ALL INDEXED COLUMNS SIZE 254',NO_INVALIDATE=>FALSE)

SELECT /*+ INDEX(T2) */
  C1,
  C2,
  C3,
  NVL2(C3,NULL,1) C4
FROM
  T2
WHERE
  C2='D00000000000000'
  AND (CASE WHEN C3 IS NULL THEN 1 ELSE NULL END)=1;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  2w9h5jm4tdzpz, child number 0
-------------------------------------
SELECT /*+ INDEX(T2) */   C1,   C2,   C3,   NVL2(C3,NULL,1) C4 FROM
T2 WHERE   C2='D00000000000000'   AND (CASE WHEN C3 IS NULL THEN 1 ELSE
NULL END)=1

Plan hash value: 941108248

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       | 10024 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID| T2           |   385 | 15015 | 10024   (1)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | IND_T2_C3_FN | 10000 |       |    20   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"='D00000000000000')
   2 - access("T2"."SYS_NC00005$"=1)

The index that we created was used, although notice that the Predicate Information section of the plan is a bit different from before, and this time we have an INDEX RANGE SCAN operation rather than an INDEX FULL SCAN operation. Once again, we found that we cannot simply state that “NULL Values are Not Stored in Indexes”.

Let’s drop the index and try just indexing the NULLs (sub-point 3 of point #4 above):

DROP INDEX IND_T2_C3_FN;

CREATE INDEX IND_T2_C3_FN ON T2 NVL2(C3,NULL,1);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T2',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR ALL HIDDEN COLUMNS SIZE 254 FOR ALL INDEXED COLUMNS SIZE 254',NO_INVALIDATE=>FALSE)

SELECT
  C1,
  C2,
  C3,
  NVL2(C3,NULL,1) C4
FROM
  T2
WHERE
  C2='D00000000000000'
  AND NVL2(C3,NULL,1)=1;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  fmsg8vztz32d2, child number 0
-------------------------------------
SELECT   C1,   C2,   C3,   NVL2(C3,NULL,1) C4 FROM   T2 WHERE
C2='D00000000000000'   AND NVL2(C3,NULL,1)=1

Plan hash value: 1513984157

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |       |       |  3282 (100)|          |
|*  1 |  TABLE ACCESS FULL| T2   |   385 | 14245 |  3282   (1)| 00:00:01 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(("C2"='D00000000000000' AND NVL2("C3",NULL,1)=1))

The index that we created was… not used? But is it not the case that the NVL2(C3,NULL,1) function result is the equivalent of the DECODE and the CASE function results? Let’s give this one another try with a hint:

SELECT /*+ INDEX(T2) */
  C1,
  C2,
  C3,
  NVL2(C3,NULL,1) C4
FROM
  T2
WHERE
  C2='D00000000000000'
  AND NVL2(C3,NULL,1)=1;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  f510adk7fqwyu, child number 0
-------------------------------------
SELECT /*+ INDEX(T2) */   C1,   C2,   C3,   NVL2(C3,NULL,1) C4 FROM
T2 WHERE   C2='D00000000000000'   AND NVL2(C3,NULL,1)=1

Plan hash value: 2303772603

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |       |       |  3740 (100)|          |
|*  1 |  TABLE ACCESS BY INDEX ROWID| T2           |   385 | 14245 |  3740   (1)| 00:00:01 |
|*  2 |   INDEX FULL SCAN           | IND_T2_C3_FN | 10000 |       |  3223   (1)| 00:00:01 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"='D00000000000000')
   2 - filter(NVL2("C3",NULL,1)=1)

That’s better, even if we did receive an INDEX FULL SCAN operation rather than in INDEX RANGE SCAN operation as was the intended result.

Something fun to think about – why did the technique using the CASE syntax that resulted in an INDEX RANGE SCAN operation have a plan with a calculated cost of 10,024, when the plans with the INDEX FULL SCAN operations have a calculated cost of about 3,750?

Comments : 18 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Full Table Scans and the Buffer Cache in 11.2 – What is Wrong with this Quote?

26 02 2012

February 26, 2012 (Modified February 27, 2012)

I found another interesting quote in the “Oracle Database 11gR2 Performance Tuning Cookbook“, this time related to tables and full table scans. This quote is found on page 170 of the book:

“If we do an FTS [full table scan], database buffers are used to read all the table data, and this situation may lead to flushing the buffer cache data to make room for the FTS data. To avoid this situation and to limit the consequences on the database buffer cache, the database blocks from FTS operations are put on the top of the LRU (Least Recently Used) list.”

What, if anything, is wrong (and/or right) with the above quote from the book?

—

Added February 27, 2012:

Part 2:

An additional interesting quote is found on page 176 related to full table scans when indexes are present. The test case that follows is slightly different than what is presented in the book, however the outcome is the same. Consider the following table and indexes (note that histograms will be created on columns C1 and C2, and that column C2 will have a single row with a 1 value and 999,999 rows with a 0 value):

CREATE TABLE T1 AS
SELECT
  ROWNUM C1,
  DECODE(ROWNUM,1,1,0) C2,
  LPAD('A',255,'A') C3
FROM
  DUAL
CONNECT BY
  LEVEL<=1000000;

CREATE UNIQUE INDEX IND_T1_C1 ON T1(C1);
CREATE INDEX IND_T1_C2 ON T1(C2);

ALTER TABLE T1 MODIFY (C1 NOT NULL, C2 NOT NULL);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE,ESTIMATE_PERCENT=>100,METHOD_OPT=>'FOR ALL INDEXED COLUMNS SIZE 254')

The test case script:

SET LINESIZE 120
SET PAGESIZE 1000

SELECT
  C1,
  C2
FROM
  T1
WHERE
  C2=1;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));
 
SELECT
  C1,
  C2
FROM
  T1
WHERE
  C2<>0;

SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

The (slightly reformatted) output from my execution of the above script on Oracle Database 11.2.0.2:

SQL> SELECT
  2    C1,
  3    C2
  4  FROM
  5    T1
  6  WHERE
  7    C2=1;

        C1         C2
---------- ----------
         1          1

SQL_ID  8fv30tbr8jdds, child number 0
-------------------------------------
SELECT   C1,   C2 FROM   T1 WHERE   C2=1

Plan hash value: 236868917

-----------------------------------------------------------------------------------------
| Id  | Operation                   | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |           |       |       |     4 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1        |     1 |     8 |     4   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | IND_T1_C2 |     1 |       |     3   (0)| 00:00:01 |
-----------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("C2"=1) 

---

SQL> SELECT
  2    C1,
  3    C2
  4  FROM
  5    T1
  6  WHERE
  7    C2<>0;

        C1         C2
---------- ----------
         1          1

SQL_ID  bu17044puyhkx, child number 0
-------------------------------------
SELECT   C1,   C2 FROM   T1 WHERE   C2<>0

Plan hash value: 3617692013

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |       |       |  3049 (100)|          |
|*  1 |  TABLE ACCESS FULL| T1   |     1 |     8 |  3049   (1)| 00:00:01 |
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("C2"<>0)

Notice in the above execution plans that the Oracle query optimizer correctly determined that only 1 row would be returned in both cases, yet in the first case an index was used, and in the second case a full table scan. The book states the following:

“Why did the database optimizer switch back to a long-running FTS operation, instead of the previous Index Range Scan? The answer is simple – indexes cannot be used when we compare values with a not equal operator.”

I have seen the above answer, with slight variations, provided in at least two other books. What, if anything, is wrong (and/or right) with the above quote from the book?

Comments : 38 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Interesting Index “Facts” – What is Wrong with these Quotes?

22 02 2012

February 22, 2012

There are some amazing (or just plain interesting) facts to be found about how indexes work in Oracle Database. One Internet site in particular that has been helpful in my understanding of Oracle indexes is Richard Foote’s blog. I occasionally see information on the Internet, in the Oracle documentation, in Metalink (My Oracle Support), and in books that conflict with one another – just how does one determine what information is correct, and what information is incorrect?

If you paid money to learn something, should you just assume that what you are learning is correct? What if test cases are included, should you just assume that the test case is showing what the document claims that the test case shows? What if, you never ask “What if?” … what if, you do not know when to ask “What if?”

As I mentioned in a previous article, I am in the process of reading and reviewing the book “Oracle Database 11gR2 Performance Tuning Cookbook“, and I seem to be spending quite a bit of time asking What if … or why does this statement not agree with what I believe to be true? For this blog article, I have pulled seven quotes from the book that will be mentioned in my review of the book – I thought that I would give the readers of this blog an opportunity to ask, “What if”. As always, I attempted to keep the length of the quotes to a minimum – just long enough so that the context (and meaning) of the quote is not lost.

#1 Page 88:

“Faster scans: tables and indexes that require full scans can see faster performance when placed in a large block size.”

#2 Page 119:

“We create the IX3_CUSTOMERS index to show how we can create a descending index, that is, an index which stores the data for one or more fields in descending order…

We can also create a function-based descending index.”

#3 Page 119:

“… this test allows us to dispel a myth. Oracle uses the indexes even if the leading columns are not referenced in the WHERE predicate of the query. We can see that in such a case, the operation will be an INDEX FAST FULL SCAN. Conversely, when we reference the leading column of the index, we will end up in an INDEX RANGE SCAN.

#4 Page 120:

“The last type [descending indexes] is useful when we want to use queries in which we want the data sorted in a mixed ascending/descending way on the fields indexed. If we use a regular index to access the data, Oracle is unable to do the sort in a mixed way, in a query like this… ORDER BY FIELD1 DESC, FIELD2“

#5 Page 127:

“However, when we have a table on which there are many INSERTs and DELETEs, we could schedule an index rebuild, because when deleting an index entry, the space is not freed in the index leaf, but just marked as deleted. If we have massive DELETE and INSERT operations, we could have a skewed index structure, which could slow performance due to intra-block fragmentation.”

#6 Page 127:

“If the value for DEL_LF_ROWS/LF_ROWS is greater than 2, or LF_ROWS is lower than LF_BLKS, or HEIGHT is 4 then the index should be rebuilt.”

#7 Page 139:

“When rows are frequently inserted, deleted, and updated, there is a performance bottleneck if we use a bitmap index. When the index is updated, all the bitmap segments are locked.”

What, if anything, is wrong (and/or right) with the above quotes from the book?

Comments : 22 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Directly Executing a Query is Slower than Returning a REFCURSOR from a PL/SQL Procedure – What is Wrong with this Quote?

20 02 2012

February 20, 2012

My copy of the “Oracle Database 11gR2 Performance Tuning Cookbook” arrived from Amazon, and I will say that I like the seven steps for solving performance problems that is found on page 12, although the diagram of the process on page 14 may lead to a condition known as Compulsive Tuning Disorder.

I am delighted to see that the book makes use of test case scripts, which often allow the reader to demonstrate that the book’s suggestion works in the reader’s Oracle environment. One such test case is provided on pages 54-55. I will not reproduce the test case script here, but the script may be found in the download library for the book, in chapter 2’s 2602_02_StoredProcedure.sql file. The download library for the book may be found by selecting the book from this page, and entering your email address.

After connecting to the database:

sqlplus /@TESTDB AS SYSDBA

The test case script compares the performance of this SQL statement that is directly executed in SQL*Plus:

SELECT PROD_ID, SUM(AMOUNT_SOLD) FROM SH.SALES GROUP BY PROD_ID;

With the performance of returning a SYS_REFCURSOR to a SQL*Plus variable that is declared as a REFCURSOR datatype. The book shows that the SQL statement executed directly in SQL*Plus required 1.26 seconds, while the method using the REFCURSOR required just 0.45 seconds, with the obvious extension being that the second method is more efficient. I tried the test case, and found that the normal SQL statement executed in SQL*Plus required 0.47 seconds, and the REFCURSOR method required just 0.26 seconds, so my results are consistent with those from the book – the REFCURSOR method shows less Elapsed time just as stated in the book.

What, if anything, is wrong with the above quote (test case) from the book?

Comments : 10 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Tables and Their Indexes Should be Located on Different Disks – What is Wrong with this Quote?

17 02 2012

February 17, 2012

As I mentioned in a previous blog article, I placed an order for the book “Oracle Database 11gR2 Performance Tuning Cookbook“, mostly because I was curious how the book would compare with the “Oracle Database 11g Performance Tuning Recipes” book (my review of that book was a total of about 35 typewritten pages in length), and some of the other Oracle performance related books that I have reviewed.

After placing my order for the book, I took a quick look at a couple of the book’s preview pages on Amazon, downloaded the sample chapter from the book publisher – chapter 10 “Tuning I/O”, and spent a bit of time reading the sample chapter (making comments in the margins of the printed pages). I circled the following paragraph (sorry for the long quote – I want to make certain that the context of the quote is not lost), found on page 422 of the book (page 17 in the PDF download):

“We can also distribute tables and related indexes on different disks, to obtain performance gain in both read and write operations. If we have tables and indexes on the same disk, we need to read and write in two different places on the same disk. By dividing the work between two disks, we can perform an index range scan faster than when the index and the table are on the same disk.”

What, if anything, is wrong with the above quote from the book? For some reason, the acronym MASE came to mind when I read the above paragraph.

Comments : 15 Comments »

Categories : General Administration, Quiz - Whose Answer is it Anyway?

Stored Outlines (Plan Stability) are an Enterprise Edition Feature? A Self-Conflicting Story

2 12 2011

December 2, 2011

An innocent question was asked in an OTN thread regarding the availability of plan stability options in the Standard Edition of Oracle Database. If we check the documentation for the latest release (11.2.0.x) of Oracle Database, we will find the following statement:

“The use of stored outlines is deprecated in Oracle Database 11g Release 1 (11.1). Instead, you should use the SQL plan management feature that enables the optimizer to maintain a history of execution plans for a SQL statement.”

OK, so stored outlines are deprecated, even though stored outlines continue to work. The documentation suggests using SQL Plan Management as a replacement for stored outlines. That seems somewhat logical, because the Oracle Database documentation for 9.2 includes in its available feature list for the various Oracle Editions:

Plan Stability:

Standard Edition: Not available

Enterprise Edition: Available

Personal Edition: Available

“Allows execution plans for SQL to be stored so that the plan remains consistent throughout schema changes, database reorganizations, and data volume changes.”

The same documentation also suggest checking the V$OPTION view to see which options are enabled for the particular Edition of Oracle Database that is installed.

Based on the information found in the documentation for the older Oracle Database version, using Outlines (Plan Stability) requires the Enterprise Edition of Oracle Database, so it seems as though the quote from the first documentation link offers a good suggestion to use the Enterprise Edition feature of SQL Plan Management in place of stored outlines. A couple of people have pointed out on this blog various documentation errors, so let’s check with Oracle support (that was a good suggestion offered by one of the responders in the OTN thread).

An easy to find article in My Oracle Support is Metalink (MOS) Doc ID 100911.1, “V$OPTION Fixed Table and Support Releases and Options”. That document states that an Enterprise Edition license is needed to use stored outlines. The document mentions Oracle Database 8i, if I recall correctly.

A quick check of the book “Performance Tuning Recipes” finds on page 412 an indication that stored outlines are only supported on the Enterprise Edition of Oracle Database.

Based on the above, the situation does not appear to be too positive for the OP in the OTN thread. Maybe we should spend some significant time digging through My Oracle Support. If we are lucky, we might stumble across the following two articles that offer a different opinion:

Metalink (MOS) Doc ID 271886.1, “Differences Between Different Editions of Oracle Database 10G Release 1
Metalink (MOS) Doc ID 161556.1, “Differences between Oracle9i Personal, Standard and Enterprise on NT/2000”

If we continue searching, we will find an indication in the “Troubleshooting Oracle Performance” book on page 248 a statement that the Standard Edition is sufficient for the use of stored outlines.

We might even take the suggestion of the Oracle Database documentation and check the V$OPTION view, after confirming that we are connected to a Standard Edition 11.2.0.2 database:

SELECT
  *
FROM
  V$VERSION;

BANNER
---------------------------------------------------------
Oracle Database 11g Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for 64-bit Windows: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

SELECT
  PARAMETER,
  VALUE
FROM
  V$OPTION
ORDER BY
  DECODE(PARAMETER,'Plan Stability','1',PARAMETER);

PARAMETER                          VALUE
---------------------------------- -----
Plan Stability                     TRUE    <---------
Active Data Guard                  FALSE
Advanced Compression               FALSE
Advanced replication               FALSE
Application Role                   FALSE
Automatic Storage Management       FALSE
Backup Encryption                  FALSE
Basic Compression                  FALSE
Bit-mapped indexes                 FALSE
Block Change Tracking              FALSE
Block Media Recovery               FALSE
Change Data Capture                FALSE
Coalesce Index                     TRUE
Connection multiplexing            TRUE
Connection pooling                 TRUE
DICOM                              TRUE
Data Mining                        FALSE
Database queuing                   TRUE
Database resource manager          FALSE
Deferred Segment Creation          FALSE
Duplexed backups                   FALSE
Enterprise User Security           FALSE
Export transportable tablespaces   FALSE
Fast-Start Fault Recovery          FALSE
File Mapping                       FALSE
Fine-grained Auditing              FALSE
Fine-grained access control        FALSE
Flashback Data Archive             FALSE
Flashback Database                 FALSE
Flashback Table                    FALSE
Incremental backup and recovery    TRUE
Instead-of triggers                TRUE
Java                               TRUE
Join index                         FALSE
Managed Standby                    FALSE
Materialized view rewrite          FALSE
OLAP                               FALSE
OLAP Window Functions              TRUE
Objects                            TRUE
Online Index Build                 FALSE
Online Redefinition                FALSE
Oracle Data Guard                  FALSE
Oracle Database Vault              FALSE
Oracle Label Security              FALSE
Parallel backup and recovery       FALSE
Parallel execution                 FALSE
Parallel load                      TRUE
Partitioning                       FALSE
Point-in-time tablespace recovery  FALSE
Proxy authentication/authorization TRUE
Real Application Clusters          FALSE
Real Application Testing           FALSE
Result Cache                       FALSE
SQL Plan Management                FALSE
Sample Scan                        TRUE
SecureFiles Encryption             FALSE
Server Flash Cache                 FALSE
Spatial                            FALSE
Streams Capture                    FALSE
Transparent Application Failover   TRUE
Transparent Data Encryption        FALSE
Trial Recovery                     FALSE
Unused Block Compression           FALSE
XStream                            TRUE

The above shows that Plan Stability is enabled for the Standard Edition, and thus usable with Standard Edition. The innocent OTN question has thus led to a lot of effort to demonstrate that not only can the Oracle Database documentation be self-conflicting, but so can the My Oracle Support site.

It is interesting to note that AWR collection and the related features in Enterprise Manager are enabled by default in the Standard Edition of Oracle Database 10.1.0.x and 10.2.0.x. However, just because these AWR related features are enabled by default does not mean that the features may be legally used in the Standard Edition of Oracle Database (or the Enterprise Edition without the additional cost Diagnostics Pack license). I recall discussions in a couple of OTN threads where posters claimed that AWR related features were “free” with the Standard Edition, because those features were enabled by default – sorry, it does not work that way (if I recall correctly, partitioning is enabled by default in the Enterprise Edition, even though it is an additional cost option).

In the OTN thread Pierre Forstmann offered the following helpful demonstration test case, which checks another item found in the V$OPTION view that is set to FALSE for the Standard Edition:

SQL> alter index emp_job_ix rebuild online;
alter index emp_job_ix rebuild online
*
ERROR at line 1:
ORA-00439: feature not enabled: Online Index Build

As such, if stored outlines were not available on the Standard Edition of Oracle Database (just as OLAP Window Functions were not in 8.1.7.4 and Online Index Build are not in 11.2.0.2), using those features should result in an ORA-00439.

A couple of helpful articles that are related to stored outlines (most written by OakTable Network members):
http://oracle-randolf.blogspot.com/2009/03/plan-stability-in-10g-using-existing.html
http://kerryosborne.oracle-guy.com/2008/12/oracle-outlines-aka-plan-stability/
http://www.oracle-base.com/articles/misc/Outlines.php
http://www.jlcomp.demon.co.uk/outline_hack.html
http://jonathanlewis.wordpress.com/2010/03/11/dropping-outln/
http://www.oracle.com/technetwork/database/focus-areas/bi-datawarehousing/twp-upgrading-10g-to-11g-what-to-ex-133707.pdf

—

Any other good self-conflicting stories related to Oracle Database?

Comments : Leave a Comment »

Categories : Quiz - Whose Answer is it Anyway?

Using TKPROF for Analyzing 10046 Extended SQL Trace Files – What is Wrong with this Quote?

21 09 2011

September 21, 2011

I have written a couple of blog articles on the topic of reading 10046 extended SQL trace files. Some of those blog articles are listed below:

Once you have collected a 10046 extended SQL trace, you can pass that trace file through TKPROF or any number of other utilities. For example, if I pick a 10046 extended SQL trace file captured at level 8 from a 10.2.0.2 database instance and pass that file through TKPROF that is supplied with Oracle Database 11.2.0.2, a portion of the TKPROF output might appear as follows:

********************************************************************************
select currency_id, sell_rate, buy_rate,  act_material_cost, act_labor_cost, act_burden_cost, act_service_cost,
tracking_currency,
s_currency, s_thousand, i_currency, i_neg_curr, i_curr_digits,
rnd_acct_id, real_gn_acct_id, real_ls_acct_id, unreal_gn_acct_id, unreal_ls_acct_id
from INV_TRANS_CURR t, currency c
where TRANSACTION_ID = 1158316
and t.currency_id = c.id
order by c.id asc                                                                                                                                                                                                                                                                                                                          

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          6          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          6          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 49 
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  NESTED LOOPS  (cr=6 pr=0 pw=0 time=125 us)
         2          2          2   TABLE ACCESS BY INDEX ROWID CURRENCY (cr=2 pr=0 pw=0 time=69 us)
         2          2          2    INDEX FULL SCAN SYS_C004588 (cr=1 pr=0 pw=0 time=37 us)(object id 12048)
         0          0          0   TABLE ACCESS BY INDEX ROWID INV_TRANS_CURR (cr=4 pr=0 pw=0 time=45 us)
         0          0          0    INDEX UNIQUE SCAN SYS_C005202 (cr=4 pr=0 pw=0 time=36 us)(object id 12327)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       5        0.00          0.00
  SQL*Net message from client                     5        0.00          0.00
  latch: library cache                            1        0.00          0.00
********************************************************************************
select euro_participant, xchg_rate from currency where id = :1             

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          2          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          2          0           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 49 
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  TABLE ACCESS BY INDEX ROWID CURRENCY (cr=2 pr=0 pw=0 time=37 us)
         1          1          1   INDEX UNIQUE SCAN SYS_C004588 (cr=1 pr=0 pw=0 time=20 us)(object id 12048)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       5        0.00          0.00
  SQL*Net message from client                     5        0.00          0.00
  latch: library cache                            1        0.00          0.00
********************************************************************************

—

My Toy Project for Performance Tuning (otherwise known as the Hyper-Extended Oracle Performance Monitor) produces several output files when reading 10046 extended SQL trace files. For example, if I pass in the same 10046 extended SQL trace file that was supplied to TKPROF, one of the output files contains information similar to the following that provides a detailed explanation of the running 10046 extended SQL trace file:

Statement Depth 0 (Application Code)
Cursor 62   Ver 2614   Parse at 90.371707  (0.004613)
select euro_participant, xchg_rate from currency where id = :1

Cursor 62   Ver 2614   Parse at 90.371704 (Parse to Parse -0.000003),CPU Time 0.000000,Elapsed Time 0.000034,Rows Affected 0,Blks from Buff 0,Blks from Disk 0,Goal=ALL_ROWS
Cursor 62   Ver 2614            90.371776  0.000001   SQL*Net message to client
Cursor 62   Ver 2614            90.371931  0.000137   SQL*Net message from client
Cursor 62   Ver 2614            90.372036  0.000001   SQL*Net message to client
Cursor 62   Ver 2614            90.372368  0.000297   SQL*Net message from client
Bind Variables (62):BINDS #62:  90.372368
   Bind#0
    oacdty=96 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=178 siz=32 off=0
    kxsbbbfp=6c8e4750  bln=32  avl=03  flg=05
    value="USD"

Cursor 62   Ver 2614 Execute at 90.372578 (Parse to Exec  0.000871),CPU Time 0.000000,Elapsed Time 0.000144,Rows Affected 0,Blks from Buff 0,Blks from Disk 0,
Cursor 62   Ver 2614            90.372604  0.000001   SQL*Net message to client
Cursor 62   Ver 2614            90.372757  0.000130   SQL*Net message from client
Cursor 62   Ver 2614            90.372826  0.000001   SQL*Net message to client
Cursor 62   Ver 2614   Fetch at 90.372860 (Parse to Fetch 0.001153),CPU Time 0.000000,Elapsed Time 0.000068,Rows Retrievd 1,Blks from Buff 2,Blks from Disk 0
Cursor 62   Ver 2614            90.373213  0.000301   SQL*Net message from client
Cursor 0   Ver 0            90.373330  0.000001   SQL*Net message to client
Cursor 0   Ver 0            90.375677  0.002331   SQL*Net message from client
...
Cursor 42   Ver 5 Execute at 90.384344 (Parse to Exec  81.475396),CPU Time 0.000000,Elapsed Time 0.000108,Rows Affected 0,Blks from Buff 0,Blks from Disk 0,
Cursor 42   Ver 5            90.384368  0.000001   SQL*Net message to client
Cursor 42   Ver 5            90.384532  0.000144   SQL*Net message from client
Cursor 42   Ver 5            90.384682  0.000001   SQL*Net message to client
Cursor 42   Ver 5   Fetch at 90.384739 (Parse to Fetch 81.475791),CPU Time 0.000000,Elapsed Time 0.000175,Rows Retrievd 1,Blks from Buff 11,Blks from Disk 0
Cursor 42   Ver 5            90.386534  0.001750   SQL*Net message from client
Cursor 38   Ver 2608            90.386582  0.000001   SQL*Net message to client
Cursor 38   Ver 2608            90.387369  0.000763   SQL*Net message from client
Cursor 38   Ver 2608            90.389990  0.000103   latch: library cache
----------------------------------------------------------------------------------
Statement Depth 0 (Application Code)
Cursor 38   Ver 2609   Parse at 90.391579  (0.010830)

select currency_id, sell_rate, buy_rate,  act_material_cost, act_labor_cost, act_burden_cost, act_service_cost,
tracking_currency,
s_currency, s_thousand, i_currency, i_neg_curr, i_curr_digits,
rnd_acct_id, real_gn_acct_id, real_ls_acct_id, unreal_gn_acct_id, unreal_ls_acct_id
from INV_TRANS_CURR t, currency c
where TRANSACTION_ID = 1158746
and t.currency_id = c.id
order by c.id asc

Cursor 38   Ver 2609   Parse at 90.391571 (Parse to Parse -0.000008),CPU Time 0.015625,Elapsed Time 0.004159,Rows Affected 0,Blks from Buff 0,Blks from Disk 0,**Shared Pool Misses** 1,Goal=ALL_ROWS
Cursor 38   Ver 2609            90.391738  0.000006   SQL*Net message to client
Cursor 38   Ver 2609            90.392021  0.000235   SQL*Net message from client
Cursor 38   Ver 2609            90.392118  0.000001   SQL*Net message to client
Cursor 38   Ver 2609            90.392607  0.000436   SQL*Net message from client

A second output file from my program provides summarized information, somewhat like TKPROF:

Total for Trace File:
|PARSEs   17914|CPU S   12.546875|CLOCK S   12.487227|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         6|CUR RD BLKs (Mem)         0|SHARED POOL MISs   3281|
|EXECs    33730|CPU S    6.328125|CLOCK S    6.450126|ROWs     1348|PHY RD BLKs         0|CON RD BLKs (Mem)      8574|CUR RD BLKs (Mem)      4631|SHARED POOL MISs     27|
|FETCHs   32222|CPU S    6.546875|CLOCK S    6.436054|ROWs    27368|PHY RD BLKs         1|CON RD BLKs (Mem)    690260|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|

Wait Event Summary:
SQL*Net message to client           0.185460  On Client/Network   Min Wait:     0.000001  Avg Wait:     0.000001  Max Wait:     0.000028  Waits: 128632
SQL*Net message from client        72.674370  On Client/Network   Min Wait:     0.000112  Avg Wait:     0.000553  Max Wait:     0.016187  Waits: 131318
log file sync                       0.180988  On DB Server        Min Wait:     0.000005  Avg Wait:     0.000150  Max Wait:     0.010718  Waits:   1209
SQL*Net more data to client         0.001780  On Client/Network   Min Wait:     0.000013  Avg Wait:     0.000018  Max Wait:     0.000026  Waits:     98
db file sequential read             0.003380  On DB Server        Min Wait:     0.003380  Avg Wait:     0.003380  Max Wait:     0.003380  Waits:      1
latch: library cache                0.000256  On DB Server        Min Wait:     0.000067  Avg Wait:     0.000085  Max Wait:     0.000103  Waits:      3

Similar SQL Statements in Group: 4253 
First Reference: Cursor 62   Ver 4   Parse at 8.941502
|PARSEs    4253|CPU S    0.109375|CLOCK S    0.149414|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|EXECs     4253|CPU S    0.671875|CLOCK S    0.655012|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|FETCHs    4253|CPU S    0.468750|CLOCK S    0.295336|ROWs     4253|PHY RD BLKs         0|CON RD BLKs (Mem)      8506|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
  CPU S 4.92%  CLOCK S 4.33%
  *    0.000153 seconds of time related to unclassified events
  *    7.060429 seconds of time related to client/network events
----------------------------------------------------------------------------------

...
Similar SQL Statements in Group: 1 
First Reference: Cursor 18   Ver 1   Parse at 8.618896
|PARSEs       1|CPU S    0.000000|CLOCK S    0.001696|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|EXECs      486|CPU S    0.078125|CLOCK S    0.065229|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         2|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|FETCHs     486|CPU S    0.812500|CLOCK S    0.771616|ROWs        0|PHY RD BLKs         1|CON RD BLKs (Mem)    148489|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
  CPU S 3.50%  CLOCK S 3.30%
  *    0.003380 seconds of time related data file I/O
  *    0.197874 seconds of time related to client/network events

Similar SQL Statements in Group: 4253
|PARSEs    4253|CPU S    0.109375|CLOCK S    0.149414|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|EXECs     4253|CPU S    0.671875|CLOCK S    0.655012|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|FETCHs    4253|CPU S    0.468750|CLOCK S    0.295336|ROWs     4253|PHY RD BLKs         0|CON RD BLKs (Mem)      8506|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|

...
Statement Depth 0 (Application Code)
Cursor 62   Ver 4   Parse at 8.941502  (TD Prev 0.011920)  Similar Cnt 1
|PARSEs       1|CPU S    0.000000|CLOCK S    0.001544|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|EXECs        1|CPU S    0.000000|CLOCK S    0.002476|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|FETCHs       1|CPU S    0.000000|CLOCK S    0.000076|ROWs        1|PHY RD BLKs         0|CON RD BLKs (Mem)         2|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
  CPU S 0.00%  CLOCK S 0.02%

select euro_participant, xchg_rate from currency where id = :1

       (Rows 1)   TABLE ACCESS BY INDEX ROWID CURRENCY (cr=2 pr=0 pw=0 time=48 us)
       (Rows 1)    INDEX UNIQUE SCAN SYS_C004588 (cr=1 pr=0 pw=0 time=24 us)

Bind Variables (62):BINDS #62:  8.944672
   Bind#0
    oacdty=96 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=178 siz=32 off=0
    kxsbbbfp=36d87e78  bln=32  avl=03  flg=05
    value="USD"

------------
Statement Depth 0 (Application Code)
Cursor 4   Ver 5   Parse at 8.976105  (TD Prev 0.004661)  Similar Cnt 2
|PARSEs       1|CPU S    0.000000|CLOCK S    0.000109|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
|EXECs        1|CPU S    0.000000|CLOCK S    0.000145|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
|FETCHs       1|CPU S    0.000000|CLOCK S    0.000071|ROWs        1|PHY RD BLKs         0|CON RD BLKs (Mem)         2|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
  CPU S 0.00%  CLOCK S 0.00%

select euro_participant, xchg_rate from currency where id = :1

       (Rows 1)   TABLE ACCESS BY INDEX ROWID CURRENCY (cr=2 pr=0 pw=0 time=40 us)
       (Rows 1)    INDEX UNIQUE SCAN SYS_C004588 (cr=1 pr=0 pw=0 time=20 us)

Bind Variables (4):BINDS #4:  8.976753
   Bind#0
    oacdty=96 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=178 siz=32 off=0
    kxsbbbfp=6c8e87d8  bln=32  avl=03  flg=05
    value="USD"

------------
Statement Depth 0 (Application Code)
Cursor 37   Ver 6   Parse at 9.020236  (TD Prev 0.004586)  Similar Cnt 3
|PARSEs       1|CPU S    0.000000|CLOCK S    0.000056|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
|EXECs        1|CPU S    0.000000|CLOCK S    0.000144|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
|FETCHs       1|CPU S    0.000000|CLOCK S    0.000067|ROWs        1|PHY RD BLKs         0|CON RD BLKs (Mem)         2|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
  CPU S 0.00%  CLOCK S 0.00%

select euro_participant, xchg_rate from currency where id = :1

       (Rows 1)   TABLE ACCESS BY INDEX ROWID CURRENCY (cr=2 pr=0 pw=0 time=37 us)
       (Rows 1)    INDEX UNIQUE SCAN SYS_C004588 (cr=1 pr=0 pw=0 time=19 us)

Bind Variables (37):BINDS #37:  9.020884
   Bind#0
    oacdty=96 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
    oacflg=01 fl2=1000000 frm=01 csi=178 siz=32 off=0
    kxsbbbfp=6c4d08e0  bln=32  avl=03  flg=05
    value="USD"
...

Similar SQL Statements in Group: 1
|PARSEs       1|CPU S    0.015625|CLOCK S    0.003585|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|EXECs        1|CPU S    0.000000|CLOCK S    0.000119|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
|FETCHs       1|CPU S    0.000000|CLOCK S    0.000111|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         6|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|

Statement Depth 0 (Application Code)
Cursor 31   Ver 4   Parse at 8.922969  (TD Prev 0.014021)  Similar Cnt 1
|PARSEs       1|CPU S    0.015625|CLOCK S    0.003585|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      1|
|EXECs        1|CPU S    0.000000|CLOCK S    0.000119|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         0|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
|FETCHs       1|CPU S    0.000000|CLOCK S    0.000111|ROWs        0|PHY RD BLKs         0|CON RD BLKs (Mem)         6|CUR RD BLKs (Mem)         0|SHARED POOL MISs      0|
  CPU S 0.06%  CLOCK S 0.02%

select currency_id, sell_rate, buy_rate,  act_material_cost, act_labor_cost, act_burden_cost, act_service_cost,
tracking_currency,
s_currency, s_thousand, i_currency, i_neg_curr, i_curr_digits,
rnd_acct_id, real_gn_acct_id, real_ls_acct_id, unreal_gn_acct_id, unreal_ls_acct_id
from INV_TRANS_CURR t, currency c
where TRANSACTION_ID = 413948
and t.currency_id = c.id
order by c.id asc

       (Rows 0)   NESTED LOOPS  (cr=6 pr=0 pw=0 time=117 us)
       (Rows 2)    TABLE ACCESS BY INDEX ROWID CURRENCY (cr=2 pr=0 pw=0 time=65 us)
       (Rows 2)     INDEX FULL SCAN SYS_C004588 (cr=1 pr=0 pw=0 time=38 us)
       (Rows 0)    TABLE ACCESS BY INDEX ROWID INV_TRANS_CURR (cr=4 pr=0 pw=0 time=37 us)
       (Rows 0)     INDEX UNIQUE SCAN SYS_C005202 (cr=4 pr=0 pw=0 time=28 us)

—

It is interesting to see how the contents of 10046 extended SQL trace files have evolved through the various Oracle Database release versions, yet at its core the file format has not really changed that much. Below are a couple of examples from different Oracle Database release versions.

8.1.7.3 10046 extended SQL trace at level 8:

=====================
PARSING IN CURSOR #38 len=287 dep=0 uid=78 oct=2 lid=78 tim=370357232 hv=3536790953 ad='5ad8bec'
INSERT INTO WORK_ORDER_SCHED (SCHEDULE_ID, WORKORDER_TYPE, WORKORDER_BASE_ID, WORKORDER_SUB_ID, WORKORDER_LOT_ID, WORKORDER_SPLIT_ID, PART_ID, START_DATE, FINISH_DATE, BITS_LENGTH, SCHEDULE_TIME, PASS_COUNT, SCHEDULE_RANK) VALUES (:1, :2, :3, :4, :5, :6, :7, :8, :9, :10, :11, :12, :13)
END OF STMT
PARSE #38:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=0,tim=370357232
WAIT #38: nam='db file sequential read' ela= 0 p1=4 p2=207930 p3=1
WAIT #38: nam='db file sequential read' ela= 2 p1=9 p2=300266 p3=1
WAIT #38: nam='db file sequential read' ela= 0 p1=9 p2=350987 p3=1
WAIT #38: nam='db file sequential read' ela= 2 p1=9 p2=300330 p3=1
WAIT #38: nam='db file sequential read' ela= 0 p1=9 p2=300339 p3=1
WAIT #38: nam='db file sequential read' ela= 0 p1=9 p2=300181 p3=1
EXEC #38:c=0,e=4,p=6,cr=1,cu=12,mis=0,r=1,dep=0,og=4,tim=370357236
WAIT #38: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #38: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1 p3=0
XCTEND rlbk=0, rd_only=0
WAIT #0: nam='log file sync' ela= 0 p1=1176 p2=0 p3=0
...
XCTEND rlbk=0, rd_only=0
WAIT #0: nam='log file sync' ela= 0 p1=1328 p2=0 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1 p3=0
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370537187
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370537187
EXEC #33:c=0,e=0,p=0,cr=11,cu=8,mis=0,r=1,dep=1,og=4,tim=370537187
WAIT #33: nam='latch free' ela= 0 p1=197748644 p2=106 p3=0
WAIT #33: nam='latch free' ela= 0 p1=197748540 p2=106 p3=0
EXEC #34:c=2,e=2,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370537189
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370537189
EXEC #33:c=3,e=3,p=0,cr=11,cu=8,mis=0,r=1,dep=1,og=4,tim=370537190
EXEC #39:c=3,e=3,p=0,cr=26,cu=20,mis=0,r=1,dep=0,og=4,tim=370537190
WAIT #39: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #39: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1 p3=0
XCTEND rlbk=0, rd_only=0
...
WAIT #0: nam='log file sync' ela= 0 p1=583 p2=0 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1 p3=0
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370580579
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370580579
EXEC #33:c=0,e=0,p=0,cr=10,cu=6,mis=0,r=1,dep=1,og=4,tim=370580579
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370580579
WAIT #34: nam='latch free' ela= 0 p1=197748644 p2=106 p3=0
EXEC #34:c=0,e=0,p=0,cr=3,cu=2,mis=0,r=1,dep=2,og=4,tim=370580579
EXEC #33:c=0,e=0,p=0,cr=10,cu=6,mis=0,r=1,dep=1,og=4,tim=370580579
EXEC #39:c=0,e=0,p=0,cr=24,cu=16,mis=0,r=1,dep=0,og=4,tim=370580579
WAIT #39: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #39: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1 p3=0
XCTEND rlbk=0, rd_only=0
...

9.2.0.4 10046 extended SQL trace at level 12:

PARSING IN CURSOR #40 len=118 dep=0 uid=23 oct=3 lid=23 tim=1160715895381603 hv=3290581551 ad='67afe40c'
select bits_length from CUST_ORDER_BINARY
where cust_order_id = :1              and type = :2                       
END OF STMT
EXEC #40:c=0,e=109,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1160715895381598
WAIT #40: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0
WAIT #40: nam='SQL*Net message from client' ela= 601 p1=1413697536 p2=1 p3=0
WAIT #40: nam='db file sequential read' ela= 20 p1=5 p2=105821 p3=1
WAIT #40: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0
FETCH #40:c=0,e=102,p=1,cr=3,cu=0,mis=0,r=1,dep=0,og=4,tim=1160715895382393
WAIT #40: nam='SQL*Net message from client' ela= 2276 p1=1413697536 p2=1 p3=0
BINDS #43:
 bind 0: dty=96 mxl=32(08) mal=00 scl=00 pre=00 oacflg=01 oacfl2=0 size=64 offset=0
   bfp=b75b4a74 bln=32 avl=08 flg=05
   value="41120-26"
 bind 1: dty=96 mxl=32(01) mal=00 scl=00 pre=00 oacflg=01 oacfl2=0 size=0 offset=32
   bfp=b75b4a94 bln=32 avl=01 flg=01
   value="D"
=====================
PARSING IN CURSOR #43 len=105 dep=0 uid=23 oct=3 lid=23 tim=1160715895384818 hv=3322014952 ad='67afc9fc'
select bits from CUST_ORDER_BINARY
where cust_order_id = :1              and type = :2                 
END OF STMT
EXEC #43:c=0,e=96,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1160715895384815
WAIT #43: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0
WAIT #43: nam='SQL*Net message from client' ela= 578 p1=1413697536 p2=1 p3=0
WAIT #43: nam='SQL*Net message to client' ela= 1 p1=1413697536 p2=1 p3=0
FETCH #43:c=0,e=38,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=4,tim=1160715895385519
WAIT #43: nam='SQL*Net message from client' ela= 7413 p1=1413697536 p2=1 p3=0
WAIT #54: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #54: nam='SQL*Net message from client' ela= 3506 p1=1413697536 p2=1 p3=0
...

10.2.0.2 10046 extended SQL trace at level 8:

EXEC #3:c=0,e=172,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2761350071
WAIT #3: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2761350121
WAIT #3: nam='SQL*Net message from client' ela= 151 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2761350309
WAIT #3: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2761350464
FETCH #3:c=0,e=178,p=0,cr=11,cu=0,mis=0,r=1,dep=0,og=1,tim=2761350529
WAIT #3: nam='SQL*Net message from client' ela= 1703 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2761352318
WAIT #38: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2761352422
WAIT #38: nam='SQL*Net message from client' ela= 14855 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2761367335
WAIT #38: nam='latch: library cache' ela= 86 address=6702518304 number=214 tries=1 obj#=-1 tim=2761370634
=====================
PARSING IN CURSOR #38 len=708 dep=0 uid=49 oct=3 lid=49 tim=2761372680 hv=3811084033 ad='7a792970'
...
EXEC #42:c=0,e=108,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2792074555
WAIT #42: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792074579
WAIT #42: nam='SQL*Net message from client' ela= 144 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792074743
WAIT #42: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792074893
FETCH #42:c=0,e=175,p=0,cr=11,cu=0,mis=0,r=1,dep=0,og=1,tim=2792074950
WAIT #42: nam='SQL*Net message from client' ela= 1750 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792076745
WAIT #38: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792076793
WAIT #38: nam='SQL*Net message from client' ela= 763 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792077580
WAIT #38: nam='latch: library cache' ela= 103 address=6702518304 number=214 tries=1 obj#=-1 tim=2792080201
=====================
PARSING IN CURSOR #38 len=709 dep=0 uid=49 oct=3 lid=49 tim=2792081790 hv=332841952 ad='6553b430'
...
WAIT #3: nam='SQL*Net message from client' ela= 132 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792095443
WAIT #3: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792096040
FETCH #3:c=15625,e=634,p=0,cr=11,cu=0,mis=0,r=1,dep=0,og=1,tim=2792096110
WAIT #3: nam='SQL*Net message from client' ela= 1645 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792097829
WAIT #62: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792097885
WAIT #62: nam='SQL*Net message from client' ela= 779 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=2792098689
WAIT #62: nam='latch: library cache' ela= 67 address=6702518784 number=214 tries=1 obj#=-1 tim=2792099425
=====================
PARSING IN CURSOR #62 len=709 dep=0 uid=49 oct=3 lid=49 tim=2792102933 hv=3211547247 ad='59a46098'

11.2.0.2 10046 extended SQL trace at level 8:

PARSING IN CURSOR #395158696 len=44 dep=0 uid=62 oct=42 lid=62 tim=279105099708 hv=1347470086 ad='0' sqlid='5pgz5gt851hs6'
ALTER SESSION SET OPTIMIZER_INDEX_COST_ADJ=5
END OF STMT
PARSE #395158696:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=279105099708
EXEC #395158696:c=0,e=33,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=279105099773
WAIT #395158696: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=0 tim=279105099786
WAIT #395158696: nam='SQL*Net message from client' ela= 29739 driver id=1413697536 #bytes=1 p3=0 obj#=0 tim=279105129537
*** SESSION ID:(4.2401) 2011-08-18 11:30:18.997

CLOSE #395158696:c=0,e=6,dep=0,type=0,tim=279105130224
=====================
PARSING IN CURSOR #395158696 len=66 dep=0 uid=62 oct=3 lid=62 tim=279105130999 hv=1053158396 ad='7ffa55c7da0' sqlid='f2q5x9szcbuzw'
SELECT
  ID,
  DESCRIPTION
FROM
  T90
WHERE
  ID BETWEEN 1 AND 400
END OF STMT
PARSE #395158696:c=0,e=745,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3691735591,tim=279105130998
EXEC #395158696:c=0,e=23,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3691735591,tim=279105131072
WAIT #395158696: nam='SQL*Net message to client' ela= 0 driver id=1413697536 #bytes=1 p3=0 obj#=0 tim=279105131099
WAIT #395158696: nam='db file sequential read' ela= 145 file#=4 block#=15211 blocks=1 obj#=70282 tim=279105131283
WAIT #395158696: nam='db file sequential read' ela= 141 file#=4 block#=3048038 blocks=1 obj#=70282 tim=279105131458
WAIT #395158696: nam='db file sequential read' ela= 124 file#=4 block#=15212 blocks=1 obj#=70282 tim=279105131606
WAIT #395158696: nam='db file sequential read' ela= 127 file#=4 block#=26658 blocks=1 obj#=69278 tim=279105131769
FETCH #395158696:c=0,e=676,p=4,cr=4,cu=0,mis=0,r=1,dep=0,og=1,plh=3691735591,tim=279105131790
WAIT #395158696: nam='SQL*Net message from client' ela= 68 driver id=1413697536 #bytes=1 p3=0 obj#=69278 tim=279105131879
WAIT #395158696: nam='db file parallel read' ela= 1187 files=1 blocks=39 requests=39 obj#=69278 tim=279105133171
WAIT #395158696: nam='db file sequential read' ela= 140 file#=4 block#=26704 blocks=1 obj#=69278 tim=279105133374
WAIT #395158696: nam='SQL*Net message to client' ela= 0 driver id=1413697536 #bytes=1 p3=0 obj#=69278 tim=279105133394
WAIT #395158696: nam='db file parallel read' ela= 1372 files=1 blocks=39 requests=39 obj#=69278 tim=279105134838
WAIT #395158696: nam='db file sequential read' ela= 128 file#=4 block#=32056 blocks=1 obj#=69278 tim=279105135092
WAIT #395158696: nam='db file parallel read' ela= 652 files=1 blocks=19 requests=19 obj#=69278 tim=279105135796
WAIT #395158696: nam='db file sequential read' ela= 142 file#=4 block#=106517 blocks=1 obj#=69278 tim=279105136038
FETCH #395158696:c=0,e=4182,p=100,cr=101,cu=0,mis=0,r=100,dep=0,og=1,plh=3691735591,tim=279105136084
...
WAIT #395158696: nam='db file parallel read' ela= 539 files=1 blocks=16 requests=16 obj#=69278 tim=279193197874
WAIT #395158696: nam='db file sequential read' ela= 123 file#=4 block#=3692381 blocks=1 obj#=69278 tim=279193198082
FETCH #395158696:c=0,e=2238,p=57,cr=58,cu=0,mis=0,r=57,dep=0,og=1,plh=3691735591,tim=279193198120
STAT #395158696 id=1 cnt=2547158 pid=0 pos=1 obj=69278 op='TABLE ACCESS BY INDEX ROWID T90 (cr=2573591 pr=2070791 pw=0 time=3919404 us cost=202973 size=216021546 card=4000399)'
STAT #395158696 id=2 cnt=2547158 pid=1 pos=1 obj=70282 op='INDEX RANGE SCAN IND_T90 (cr=30646 pr=5238 pw=0 time=891170 us cost=426 size=0 card=4071715)'
WAIT #395158696: nam='SQL*Net message from client' ela= 13470 driver id=1413697536 #bytes=1 p3=0 obj#=69278 tim=279193211655

—

While reading the Oracle 11g Performance Tuning Recipes book I have found a number of interesting bits of information. For example, at the bottom of page 334 and the top of page 335 is the following interesting quote:

“A locking situation is a good example where you can visually inspect a raw trace file. TKPROF doesn’t provide you details about latches and locks (enqueues). If you suspect that a query was waiting on a lock, digging deep into a raw trace file shows you exactly where and why a query was waiting. In the WAIT line, the elapsed time (ela) shows the amount of time waited (in microseconds).”

What, if anything, is wrong with the above quote from the book?

Comments : 6 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Inline Views – What is Wrong with this Quote?

18 09 2011

September 18, 2011

I do not recall putting together any articles about inline views, so let’s start out with a couple of examples before taking a look at a quote. We need to create a table for this example, so I will reuse a slightly modified table creation script from another article, and also collect statistics with 100% sampling.

DROP TABLE T1 PURGE;

CREATE TABLE T1(
  C1 NUMBER,
  C2 NUMBER,
  C3 NUMBER,
  C4 DATE,
  C5 DATE,
  C6 DATE,
  C7 VARCHAR2(20),
  C8 VARCHAR2(20),
  C9 VARCHAR2(20),
  PRIMARY KEY(C1));

INSERT INTO
  T1
SELECT
  ROWNUM,
  DECODE(MOD(ROWNUM,5),0,NULL,ROWNUM),
  DECODE(MOD(ROWNUM,5),0,NULL,ROWNUM),
  TRUNC(SYSDATE)+TRUNC(ROWNUM/100),
  DECODE(MOD(ROWNUM,5),0,NULL,TRUNC(SYSDATE)+TRUNC(ROWNUM/100)),
  DECODE(MOD(ROWNUM,5),0,NULL,TRUNC(SYSDATE)+TRUNC(ROWNUM/100)),
  RPAD(CHR(MOD(ROWNUM-1,26)+65)||
    CHR(MOD(ROWNUM,26)+65)||
    CHR(MOD(ROWNUM+1,26)+65)||
    CHR(MOD(ROWNUM+2,26)+65),20,'A'),
  DECODE(MOD(ROWNUM,5),0,NULL,
   RPAD(CHR(MOD(ROWNUM-1,26)+65)||
    CHR(MOD(ROWNUM,26)+65)||
    CHR(MOD(ROWNUM+1,26)+65)||
    CHR(MOD(ROWNUM+2,26)+65),20,'A')),
  DECODE(MOD(ROWNUM,5),0,NULL,
   RPAD(CHR(MOD(ROWNUM-1,26)+65)||
    CHR(MOD(ROWNUM,26)+65)||
    CHR(MOD(ROWNUM+1,26)+65)||
    CHR(MOD(ROWNUM+2,26)+65),20,'A'))
FROM
  DUAL
CONNECT BY
  LEVEL<=200000;

COMMIT;

CREATE INDEX IND_T1_C2 ON T1(C2);
CREATE INDEX IND_T1_C7 ON T1(C7);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE,ESTIMATE_PERCENT=>NULL)

Now, let’s create a simple SQL statement that references the above table 3 times, twice in inline views and once again outside of an inline view:

SET AUTOTRACE TRACEONLY EXPLAIN

SELECT
  T1.C1,
  T1.C2
FROM
  T1,
  (SELECT
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000) V1,
  (SELECT
     C1,
     C6,
     C7,
     C8
   FROM
     T1
   WHERE
     C1 BETWEEN 9000 AND 12000) V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

If I execute the above on Oracle Database 11.2.0.2 I see the following autotrace generated execution plan:

Execution Plan
----------------------------------------------------------
Plan hash value: 3832506612

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |  1002 | 10020 |    17   (0)| 00:00:22 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1           |  1002 | 10020 |    17   (0)| 00:00:22 |
|*  2 |   INDEX RANGE SCAN          | SYS_C0039297 |  1002 |       |     3   (0)| 00:00:04 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("T1"."C1">=9000 AND "T1"."C1"<=10000)

Notice in my query I did not reference any of the columns in view V1 or view V2 – the table T1 appears only a single time in the execution plan. Let’s fix the query and try again:

SELECT
  T1.C1,
  T1.C2,
  V1.C3,
  V1.C4,
  V2.C6,
  V2.C7,
  V2.C8
FROM
  T1,
  (SELECT
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000) V1,
  (SELECT
     C1,
     C6,
     C7,
     C8
   FROM
     T1
   WHERE
     C1 BETWEEN 9000 AND 12000) V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

Execution Plan
----------------------------------------------------------
Plan hash value: 3832506612

--------------------------------------------------------------------------------------------
| Id  | Operation                   | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |              |  1002 | 68136 |    17   (0)| 00:00:22 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T1           |  1002 | 68136 |    17   (0)| 00:00:22 |
|*  2 |   INDEX RANGE SCAN          | SYS_C0039297 |  1002 |       |     3   (0)| 00:00:04 |
--------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("T1"."C1">=9000 AND "T1"."C1"<=10000)

The above was the desired result.

Let’s create a second table that is identical to the first table:

DROP TABLE T2 PURGE;

CREATE TABLE T2(
  C1 NUMBER,
  C2 NUMBER,
  C3 NUMBER,
  C4 DATE,
  C5 DATE,
  C6 DATE,
  C7 VARCHAR2(20),
  C8 VARCHAR2(20),
  C9 VARCHAR2(20),
  PRIMARY KEY(C1));

INSERT INTO
  T2
SELECT
  ROWNUM,
  DECODE(MOD(ROWNUM,5),0,NULL,ROWNUM),
  DECODE(MOD(ROWNUM,5),0,NULL,ROWNUM),
  TRUNC(SYSDATE)+TRUNC(ROWNUM/100),
  DECODE(MOD(ROWNUM,5),0,NULL,TRUNC(SYSDATE)+TRUNC(ROWNUM/100)),
  DECODE(MOD(ROWNUM,5),0,NULL,TRUNC(SYSDATE)+TRUNC(ROWNUM/100)),
  RPAD(CHR(MOD(ROWNUM-1,26)+65)||
    CHR(MOD(ROWNUM,26)+65)||
    CHR(MOD(ROWNUM+1,26)+65)||
    CHR(MOD(ROWNUM+2,26)+65),20,'A'),
  DECODE(MOD(ROWNUM,5),0,NULL,
   RPAD(CHR(MOD(ROWNUM-1,26)+65)||
    CHR(MOD(ROWNUM,26)+65)||
    CHR(MOD(ROWNUM+1,26)+65)||
    CHR(MOD(ROWNUM+2,26)+65),20,'A')),
  DECODE(MOD(ROWNUM,5),0,NULL,
   RPAD(CHR(MOD(ROWNUM-1,26)+65)||
    CHR(MOD(ROWNUM,26)+65)||
    CHR(MOD(ROWNUM+1,26)+65)||
    CHR(MOD(ROWNUM+2,26)+65),20,'A'))
FROM
  DUAL
CONNECT BY
  LEVEL<=200000;

COMMIT;

CREATE INDEX IND_T2_C2 ON T2(C2);
CREATE INDEX IND_T2_C7 ON T2(C7);

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T2',CASCADE=>TRUE,ESTIMATE_PERCENT=>NULL)

Let’s modify the last query to access the table T2 in the second inline view and take a look at the autotrace generated execution plan for the query:

SET AUTOTRACE TRACEONLY EXPLAIN

SELECT
  T1.C1,
  T1.C2,
  V1.C3,
  V1.C4,
  V2.C6,
  V2.C7,
  V2.C8
FROM
  T1,
  (SELECT
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000) V1,
  (SELECT
     C1,
     C6,
     C7,
     C8
   FROM
     T2
   WHERE
     C1 BETWEEN 9000 AND 12000) V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

Execution Plan
----------------------------------------------------------
Plan hash value: 2810660667

---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |              |  1001 | 73073 |    35   (3)| 00:00:44 |
|*  1 |  HASH JOIN                   |              |  1001 | 73073 |    35   (3)| 00:00:44 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1           |  1002 | 23046 |    17   (0)| 00:00:22 |
|*  3 |    INDEX RANGE SCAN          | SYS_C0039297 |  1002 |       |     3   (0)| 00:00:04 |
|   4 |   TABLE ACCESS BY INDEX ROWID| T2           |  1002 | 50100 |    17   (0)| 00:00:22 |
|*  5 |    INDEX RANGE SCAN          | SYS_C0039300 |  1002 |       |     3   (0)| 00:00:04 |
---------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="C1")
   3 - access("T1"."C1">=9000 AND "T1"."C1"<=10000)
   5 - access("C1">=9000 AND "C1"<=10000)

If you do not like inline views you can instead take advantage of subquery factoring (WITH blocks):

WITH
  V1 AS (SELECT
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000),
  V2 AS (SELECT
     C1,
     C6,
     C7,
     C8
   FROM
     T2
   WHERE
     C1 BETWEEN 9000 AND 12000)
SELECT
  T1.C1,
  T1.C2,
  V1.C3,
  V1.C4,
  V2.C6,
  V2.C7,
  V2.C8
FROM
  T1,
  V1,
  V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

Execution Plan
----------------------------------------------------------
Plan hash value: 2810660667

---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |              |  1001 | 73073 |    35   (3)| 00:00:44 |
|*  1 |  HASH JOIN                   |              |  1001 | 73073 |    35   (3)| 00:00:44 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1           |  1002 | 23046 |    17   (0)| 00:00:22 |
|*  3 |    INDEX RANGE SCAN          | SYS_C0039297 |  1002 |       |     3   (0)| 00:00:04 |
|   4 |   TABLE ACCESS BY INDEX ROWID| T2           |  1002 | 50100 |    17   (0)| 00:00:22 |
|*  5 |    INDEX RANGE SCAN          | SYS_C0039300 |  1002 |       |     3   (0)| 00:00:04 |
---------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="C1")
   3 - access("T1"."C1">=9000 AND "T1"."C1"<=10000)
   5 - access("C1">=9000 AND "C1"<=10000)

—

Hints may be used to change the optimization behavior of the query optimizer. For instance, if we specify the NO_QUERY_TRANSFORMATION hint in the last of the above queries that used inline views, the autotrace generated execution plan appears as follows:

SELECT /*+ NO_QUERY_TRANSFORMATION */
  T1.C1,
  T1.C2,
  V1.C3,
  V1.C4,
  V2.C6,
  V2.C7,
  V2.C8
FROM
  T1,
  (SELECT
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000) V1,
  (SELECT
     C1,
     C6,
     C7,
     C8
   FROM
     T2
   WHERE
     C1 BETWEEN 9000 AND 12000) V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

Execution Plan
----------------------------------------------------------
Plan hash value: 3681900949

------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |              |  1002 | 91182 |  1037   (1)| 00:21:33 |
|*  1 |  HASH JOIN                      |              |  1002 | 91182 |  1037   (1)| 00:21:33 |
|   2 |   NESTED LOOPS                  |              |       |       |            |          |
|   3 |    NESTED LOOPS                 |              |  1002 | 45090 |  1019   (0)| 00:21:11 |
|   4 |     VIEW                        |              |  1002 | 35070 |    17   (0)| 00:00:22 |
|   5 |      TABLE ACCESS BY INDEX ROWID| T1           |  1002 | 18036 |    17   (0)| 00:00:22 |
|*  6 |       INDEX RANGE SCAN          | SYS_C0039297 |  1002 |       |     3   (0)| 00:00:04 |
|*  7 |     INDEX UNIQUE SCAN           | SYS_C0039297 |     1 |       |     0   (0)| 00:00:01 |
|   8 |    TABLE ACCESS BY INDEX ROWID  | T1           |     1 |    10 |     1   (0)| 00:00:02 |
|   9 |   VIEW                          |              |  1002 | 46092 |    17   (0)| 00:00:22 |
|  10 |    TABLE ACCESS BY INDEX ROWID  | T2           |  1002 | 50100 |    17   (0)| 00:00:22 |
|* 11 |     INDEX RANGE SCAN            | SYS_C0039300 |  1002 |       |     3   (0)| 00:00:04 |
------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="V2"."C1")
   6 - access("C1">=9000 AND "C1"<=10000)
   7 - access("T1"."C1"="V1"."C1")
  11 - access("C1">=9000 AND "C1"<=10000)

For fun, on the Enterprise Edition of Oracle Database (~~if I remember correctly, the Standard Edition will behave differently~~ – Edit Sept. 18, 2011: just tested 11.2.0.2 Standard Edition and 10.2.0.5 Standard Edition – both versions generated execution plans similar to what is displayed below, so the MATERIALIZE hint apparently does not behave differently as originally described) we can also use the MATERIALIZE hint using the subquery factored (WITH block) version of the query:

WITH
  V1 AS (SELECT /*+ MATERIALIZE */
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000),
  V2 AS (SELECT /*+ MATERIALIZE */
     C1,
     C6,
     C7,
     C8
   FROM
     T2
   WHERE
     C1 BETWEEN 9000 AND 12000)
SELECT
  T1.C1,
  T1.C2,
  V1.C3,
  V1.C4,
  V2.C6,
  V2.C7,
  V2.C8
FROM
  T1,
  V1,
  V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

Execution Plan
----------------------------------------------------------
Plan hash value: 1193025797

-----------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name                      | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                           |   150 | 13650 |  1491   (1)| 00:31:00 |
|   1 |  TEMP TABLE TRANSFORMATION    |                           |       |       |            |          |
|   2 |   LOAD AS SELECT              | SYS_TEMP_0FD9D6625_D08144 |       |       |            |          |
|   3 |    TABLE ACCESS BY INDEX ROWID| T1                        | 10000 |   224K|   151   (0)| 00:03:09 |
|*  4 |     INDEX RANGE SCAN          | SYS_C0039297              | 10000 |       |    20   (0)| 00:00:25 |
|   5 |   LOAD AS SELECT              | SYS_TEMP_0FD9D6626_D08144 |       |       |            |          |
|   6 |    TABLE ACCESS BY INDEX ROWID| T2                        |  3002 |   146K|    47   (0)| 00:00:59 |
|*  7 |     INDEX RANGE SCAN          | SYS_C0039300              |  3002 |       |     7   (0)| 00:00:09 |
|*  8 |   HASH JOIN                   |                           |   150 | 13650 |  1293   (1)| 00:26:53 |
|*  9 |    HASH JOIN                  |                           |  3002 |   164K|  1276   (1)| 00:26:31 |
|  10 |     VIEW                      |                           |  3002 |   134K|    12   (0)| 00:00:15 |
|  11 |      TABLE ACCESS FULL        | SYS_TEMP_0FD9D6626_D08144 |  3002 |   146K|    12   (0)| 00:00:15 |
|  12 |     TABLE ACCESS FULL         | T1                        |   200K|  1953K|  1263   (0)| 00:26:16 |
|  13 |    VIEW                       |                           | 10000 |   341K|    17   (0)| 00:00:22 |
|  14 |     TABLE ACCESS FULL         | SYS_TEMP_0FD9D6625_D08144 | 10000 |   224K|    17   (0)| 00:00:22 |
-----------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access("C1">=1 AND "C1"<=10000)
   7 - access("C1">=9000 AND "C1"<=12000)
   8 - access("T1"."C1"="V1"."C1")
   9 - access("T1"."C1"="V2"."C1")

Ouch, an estimated 31 minutes to complete?

SET AUTOTRACE OFF

SELECT
  PNAME,
  PVAL1
FROM
  SYS.AUX_STATS$
WHERE
  PNAME IN ('SREADTIM','MREADTIM');

PNAME         PVAL1
-------- ----------
SREADTIM   1247.132
MREADTIM   3575.567

Must be that darn floppy RAID 10 array again. Let’s make it faster:

EXEC DBMS_STATS.SET_SYSTEM_STATS('SREADTIM',0.4)
EXEC DBMS_STATS.SET_SYSTEM_STATS('MREADTIM',0.8)

SET AUTOTRACE TRACEONLY EXPLAIN

WITH
  V1 AS (SELECT /*+ MATERIALIZE */
     C1,
     C2,
     C3,
     C4
   FROM
     T1
   WHERE
     C1 BETWEEN 1 AND 10000),
  V2 AS (SELECT /*+ MATERIALIZE */
     C1,
     C6,
     C7,
     C8
   FROM
     T2
   WHERE
     C1 BETWEEN 9000 AND 12000)
SELECT
  T1.C1,
  T1.C2,
  V1.C3,
  V1.C4,
  V2.C6,
  V2.C7,
  V2.C8
FROM
  T1,
  V1,
  V2
WHERE
  T1.C1=V1.C1
  AND T1.C1=V2.C1;

Execution Plan
----------------------------------------------------------
Plan hash value: 1626848331

-----------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name                      | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |                           |   150 | 13650 |  1211  (10)| 00:00:01 |
|   1 |  TEMP TABLE TRANSFORMATION    |                           |       |       |            |          |
|   2 |   LOAD AS SELECT              | SYS_TEMP_0FD9D6627_D08144 |       |       |            |          |
|   3 |    TABLE ACCESS BY INDEX ROWID| T1                        | 10000 |   224K|   158   (5)| 00:00:01 |
|*  4 |     INDEX RANGE SCAN          | SYS_C0039297              | 10000 |       |    23  (14)| 00:00:01 |
|   5 |   LOAD AS SELECT              | SYS_TEMP_0FD9D6628_D08144 |       |       |            |          |
|   6 |    TABLE ACCESS BY INDEX ROWID| T2                        |  3002 |   146K|    49   (5)| 00:00:01 |
|*  7 |     INDEX RANGE SCAN          | SYS_C0039300              |  3002 |       |     8  (13)| 00:00:01 |
|*  8 |   HASH JOIN                   |                           |   150 | 13650 |  1004  (11)| 00:00:01 |
|*  9 |    HASH JOIN                  |                           |  3002 |   164K|   987  (10)| 00:00:01 |
|  10 |     VIEW                      |                           |  3002 |   134K|    10  (10)| 00:00:01 |
|  11 |      TABLE ACCESS FULL        | SYS_TEMP_0FD9D6628_D08144 |  3002 |   146K|    10  (10)| 00:00:01 |
|  12 |     TABLE ACCESS FULL         | T1                        |   200K|  1953K|   950   (8)| 00:00:01 |
|  13 |    VIEW                       |                           | 10000 |   341K|    15  (20)| 00:00:01 |
|  14 |     TABLE ACCESS FULL         | SYS_TEMP_0FD9D6627_D08144 | 10000 |   224K|    15  (20)| 00:00:01 |
-----------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access("C1">=1 AND "C1"<=10000)
   7 - access("C1">=9000 AND "C1"<=12000)
   8 - access("T1"."C1"="V1"."C1")
   9 - access("T1"."C1"="V2"."C1")

A one second estimated completion time, that is better. Bugs…

—

Now that hopefully everyone is on the same page about what an inline view is and how to use one in a query, let’s take a look at two quotes about inline views from the book Oracle 11g Performance Tuning Recipes:

Page 291 (click the link to see the quote in full context):

“While extremely useful, if misused or overused, inline views can cause database performance issues, especially in terms of the use of the temporary tablespace. Since inline views are created and used only for the duration of a query, their results are held in the program global memory area, and if too large, the temporary tablespace.”

Page 292 (note that this quote is quite a bit longer than I would prefer, but it is as short as possible without losing the context of the quote):

“In this query, there are three inline views created: the SERVICE_INFO view, the PRODUCT_INFO view, and the BILLING_INFO view. Each of these queries will be processed and the results stored in the program global area or the temporary tablespace before finally processing the true end-user query, which starts with the final SELECT statement shown in the query. In examples such as these, it is generally more efficient at the database level to create tables that hold the data defined by the inline views—in this case, three separate tables. Then, the final query can be extracted from joining the three permanent tables to generate the results.”

What, if anything, is wrong with the above quote from the book?

Comments : 7 Comments »

Categories : Quiz - Whose Answer is it Anyway?

10046 Extended SQL Tracing for a Session – What is Wrong with this Quote?

16 09 2011

September 16, 2011

While reading the Oracle 11g Performance Tuning Recipes book, I noticed that some of the recipes in chapter 10 seemed to have an odd familiarity, although as of yet I have not quite pinpointed where I had previously seen some of the concepts in chapter 10. Recipes 10-2, 10-11, and 10-16 seem to share a common ancestry with a blog article, but maybe I am imagining things. A quote from recipe 10-16, found on page 351 (page 351 is currently unavailable for me in Google Books, but page 352 is available – you might need to scroll down one page if you click this link) of the book is certainly interesting, using a named event that was introduced with Oracle Database 11.1, rather than the event number 10046:

Execute the alter session (or alter system) set events command to trace a session by its operating system process ID which is shown by the SPID column in the V$PROCESS view [the book demonstrates replacing the word pid in the following command with the SPID value from V$PROCESS] . The general format of this command is as follows:
alter session set events 'sql_trace {process:pid}'

For additional clarification, the book provides the following extended example:

alter session set events 'sql_trace {process : pid = <pid>, pname = <pname>, orapid = <orapid>} rest of event specification'

Interesting… a slight distraction (requires a sign-on for My Oracle Support) Metalink (MOS) Doc ID 813737.1, “How To Use The New 11g Events++ Syntax For Easier SQL Tracing Of Datapump Operations” – I wonder if I had read that article in the past?

What, if anything, is wrong with the above quote from the book?

Comments : 8 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Unindexed Foreign Keys – What is Wrong with this Quote?

5 09 2011

September 5, 2011

I often look for easier ways to accomplish time consuming tasks, and I suspect that is part of the reason why I buy so many computer books. In Recipe 2-5 (page 60) of the “Oracle Database 11g Performance Tuning Recipes” book there is a SQL statement to determine which database columns (owned by the user) have foreign key constraints without indexes. The same SQL statement is also found on page 243 of the book Oracle SQL Recipes: A Problem-Solution Approach. What caught my attention is the length of the SQL statement – it is considerably shorter than the SQL statement I had been using, so that should certainly reduce the amount of unnecessary typing (and free up a couple of bytes in the library cache). The SQL statement as it appears in these two books:

select
  a.constraint_name cons_name
 ,a.table_name tab_name
 ,b.column_name cons_column
 ,nvl(c.column_name,'***No Index***') ind_column
from user_constraints a
     join
     user_cons_columns b on a.constraint_name = b.constraint_name
     left outer join
     user_ind_columns c on b.column_name = c.column_name
                       and b.table_name = c.table_name
where constraint_type = 'R'
order by 2,1;

Using A, B, and C for table aliases… that must be what is wrong with the above SQL statement.

What, if anything, is wrong with the above quote from the book?

—

In case you are wondering, the following is the SQL statement that I had been using to locate unindexed foreign key columns (this SQL statement is based on a SQL statement that was found in the Expert Oracle Database Architecture book).

SELECT
  DECODE(B.TABLE_NAME, NULL, '*Check*', 'OK' ) STATUS,
  A.OWNER,
  A.TABLE_NAME,
  A.COLUMNS,
  B.COLUMNS INDEX_COLUMNS
FROM
  (SELECT
    A.OWNER,
    SUBSTR(A.TABLE_NAME,1,30) TABLE_NAME,
    SUBSTR(A.CONSTRAINT_NAME,1,30) CONSTRAINT_NAME,
    MAX(DECODE(POSITION, 1,     SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 2,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 3,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 4,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 5,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 6,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 7,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 8,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION, 9,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,10,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,11,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,12,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,13,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,14,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,15,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) ||
    MAX(DECODE(POSITION,16,', '||SUBSTR(COLUMN_NAME,1,30),NULL)) COLUMNS
  FROM
    DBA_CONS_COLUMNS A,
    DBA_CONSTRAINTS B
  WHERE
    A.CONSTRAINT_NAME = B.CONSTRAINT_NAME
    AND A.OWNER=B.OWNER
    AND B.CONSTRAINT_TYPE = 'R'
  GROUP BY
    A.OWNER,
    SUBSTR(A.TABLE_NAME,1,30),
    SUBSTR(A.CONSTRAINT_NAME,1,30) ) A,
    (SELECT
      TABLE_OWNER,
      SUBSTR(TABLE_NAME,1,30) TABLE_NAME,
      SUBSTR(INDEX_NAME,1,30) INDEX_NAME,
      MAX(DECODE(COLUMN_POSITION, 1,
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 2,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 3,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 4,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 5,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 6,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 7,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 8,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION, 9,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,10,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,11,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,12,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,13,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,14,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,15,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) ||
      MAX(DECODE(COLUMN_POSITION,16,', '||
      SUBSTR(COLUMN_NAME,1,30),NULL)) COLUMNS
    FROM
      DBA_IND_COLUMNS
    GROUP BY
      TABLE_OWNER,
      SUBSTR(TABLE_NAME,1,30),
      SUBSTR(INDEX_NAME,1,30)) B
    WHERE
      A.TABLE_NAME = B.TABLE_NAME (+)
      AND A.OWNER=B.TABLE_OWNER(+)
      AND B.COLUMNS (+) LIKE A.COLUMNS || '%'
ORDER BY
  A.OWNER,
  A.TABLE_NAME;

—

Are you feeling that it might be an ANSI problem with the book’s SQL statement? I certainly would prefer to use the shorter version of the SQL statement – I have an aversion to unnecessary typing.

—

While on the subject of creating indexes on foreign key columns, are those indexes created just to reduce the chance of deadlocks, or is it done primarily for SELECT query performance as described in the book (Google Books view)? think about this question a bit.

Comments : 23 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Parse CPU to Parse Elapsd – What is Wrong with this Quote?

1 09 2011

September 1, 2011

I located another interesting statement in the “Oracle Database 11g Performance Tuning Recipes” book, so I thought that it was time for another blog article that takes a look at a statement from the book. Chapter 4 of the book is significantly better written (much more accurate) than chapter 3.

To set the stage, let’s take a look at the “Instance Efficiency Percentages” section of two AWR reports that I have collected over the years:

Example #1:

Instance Efficiency Percentages
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:  100.00
            Buffer  Hit   %:   27.89    In-memory Sort %:  100.00
            Library Hit   %:   91.32        Soft Parse %:   76.52
         Execute to Parse %:   30.71         Latch Hit %:  100.00
Parse CPU to Parse Elapsd %:   10.26     % Non-Parse CPU:   92.99

Example #2:

Instance Efficiency Percentages
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:  100.00
               Buffer Hit %:   99.89    In-memory Sort %:  100.00
              Library Hit %:   97.45        Soft Parse %:   97.79
         Execute to Parse %:   97.30         Latch Hit %:   95.31
Parse CPU to Parse Elapsd %:   79.21       Non-Parse CPU:   99.10

For obvious reasons, it is not a desirable outcome to see that a large percentage of the CPU time consumed by a database instance is used for parsing. Ideally, most of the CPU time would be consumed actually executing the SQL statements submitted by user sessions.

Now let’s take a look at the quote from Recipe 4-10 on page 133:

“The Parse CPU to Parse Elapsd metric shows how much time the CPU is spending parsing SQL statements. The lower this metric is, the better. In the following example [not quoted], it is about 2%, which is very low. If this metric ever gets to 5%, it may mean investigation is warranted to determine why the CPU is spending this much time simply parsing SQL statements.”

What, if anything, is wrong with the above quote from the book?

Comments : 13 Comments »

Categories : Quiz - Whose Answer is it Anyway?

KEEP Pool – What is Wrong with this Quote?

28 08 2011

August 28, 2011

The book “Oracle Database 11g Performance Tuning Recipes” is out of the alpha stage – if you bought the alpha version from Apress, you should now be able to download the finished book. I am currently reviewing the book review notes that I started collecting when reading the alpha version, so that I may see if any problems I found in the alpha version of the book are also found in the final printed version of the book. My final version of the book review for this book could be interesting… stay tooned (yes, an intentional typo).

One of the sections of the book that survived the alpha stage of the book is Recipe 3-2 Managing Buffer Pools, found on page 87. The first paragraph under the Solution heading states the following (note that I removed a couple of sentences from the middle of the paragraph, so the words in [brackets] were added to paraphrase the other sentences):

“You can use multiple buffer pools instead of Oracle’s single default buffer pool, to ensure that frequently used segments stay cached in the buffer pool without being recycled out of the buffer pool… For example, if you want a segment to be cached (or pinned) in the buffer pool, you must specify the KEEP buffer pool [when creating the segment].”

*** Note that this section of the book is NOT suggesting the use of multiple block sizes in a single database, but is trying to suggest why KEEP and RECYCLE buffer pools should be used in addition to the DEFAULT buffer pool.

What, if anything, is wrong with the above quote from the book?

Comments : 12 Comments »

Categories : Quiz - Whose Answer is it Anyway?

The CURSOR_SHARING Parameter is a Silver Bullet – What is Wrong with this Quote?

3 07 2011

July 3, 2011 (Modified July 5, 2011)

Define Yah-but: Almost like yeah but, but with one missing letter.

While reading the alpha edition of the “Oracle Database 11g Performance Tuning Recipes” book, specifically recipe 5-19, I found a couple of interesting comments about the CURSOR_SHARING parameter, specifically the FORCE and SIMILAR parameter values. The quotes (as usual, trying to minimize the amount of material that is quoted without losing the context of the quotes):

“The CURSOR_SHARING parameter is one of the few Oracle Silver bullets that’ll improve database performance immediately by eliminating latch contention. Use it with confidence when dealing with library cache latch contention.”

“Thus, the SIMILAR setting seems a safer way to go about forcing the database to use bind variables instead of literals. Although there are some concerns about the safety of setting of the CURSOR_SHARING parameter to FORCE, we haven’t seen any real issues with using this setting.”

I would have expected to find the phrase silver bullet in another book, such as the book “Expert Oracle Database Architecture: Oracle Database Programming 9i, 10g, and 11g Techniques and Solutions, Second Edition“, specifically page 48:

“Note: There are no silver bullets, none. If there were any, they would be the default behavior and you would never hear about them.”

Or possibly in a presentation titled “Playing Russian Roulette with Silver Bullets”, specifically Page 14 (slide 27).

The phrase might also appear in the book “Oracle Tuning the Definitive Reference, Second Edition” specifically page 105 (the phrase silver bullet actually appears on page 102, this quote is related to the second half of the quote at the start of this article):

“Note that in Oracle 11g, cursor_sharing=similar has been debugged, and it is now possible to use cursor sharing with bind variable peeking.”

Strangely, the phrase silver bullet might also appear on a page found in the toadworld.com domain (Edit: July 5, 2011: ~~I suspect that the same advice might also be found in that author’s recent book~~ Per the book author’s comment attached below, this assumption is incorrect):

“The CURSOR_SHARING is one of the few Oracle parameters that can have a ‘silver bullet’ effect – instantly and dramatically increasing throughput on a parse-constrained database.”

I still have fond memories of the problems caused by the October 2006 patch for Oracle Database 10.2.0.2 that were related to setting the CURSOR_SHARING parameter to FORCE. That problem seems to be related to this article: Metalink (MOS) Doc ID 7272297.8, Bug 7272297 – “Memory corruption / OERI[17114] / OERI[17125] with literal replacement”.

Of course there are plenty of other resources that suggest utilizing the CURSOR_SHARING parameter to tune performance, including this article that suggests changing that parameter value to SIMILAR.

Is changing the CURSOR_SHARING parameter from EXACT to either FORCE or SIMILAR a good idea, much less a silver bullet? Was it only a problem with Oracle Database release versions prior to 11.1?

A couple of additonal resources to help you decide:

Carol Dacko reports that the SIMILAR parameter value for the CURSOR_SHARING parameter is deprecated (obsolete) as of Oracle Database 11.1 (and it will be removed in 12.1) per Metalink (MOS) Doc ID: 1169017.1
The Oracle Optimizer Group answers the question: “Why do I have hundreds of child cursors when cursor_sharing is set to similar in 10g”
The Oracle Optimizer Group explains adaptive cursor sharing behavior with cursor_sharing = similar and force
Kyle Hailey and Randolf Geist discuss the CURSOR_SHARING parameter in a blog article titled “Cursor_sharing: a picture is worth a 1000 words“

Comments : 13 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Find Objects with the Greatest Wait Time – What is Wrong with this Quote?

28 06 2011

June 28, 2011

While reading the alpha edition of the “Oracle Database 11g Performance Tuning Recipes” book, I noticed a couple of interesting SQL statements in Recipe 5-17 that just did not look right. One of those SQL statements, slightly reformatted, appears below:

SELECT
  A.CURRENT_OBJ#,
  O.OBJECT_NAME,
  O.OBJECT_TYPE,
  A.EVENT,
  SUM(A.WAIT_TIME + A.TIME_WAITED) TOTAL_WAIT_TIME
FROM
  V$ACTIVE_SESSION_HISTORY A,
  DBA_OBJECTS D
WHERE
  A.SAMPLE_TIME BETWEEN SYSDATE – 30/2880 AND SYSDATE
  AND A.CURRENT_OBJ# = D.OBJECT_ID
GROUP BY
  A.CURRENT_OBJ#,
  D.OBJECT_NAME,
  D.OBJECT_TYPE,
  A.EVENT
ORDER BY
  TOTAL_WAIT_TIME;

The above SQL statement is supposed to retrieve a list of object names that experienced the most wait time in the last 15 minutes. What is wrong with the query? Consider that a slight variation of the above query is found in the following locations:

Page 1,170 of the book “Expert Oracle Database 11g Administration“
An OTN thread where the original poster claimed that the query required too much time to execute.
An undated news article.
Page 213 of the book “Oracle Tuning: The Definitive Reference, Second Edition“
Page 160 of the book “Oracle Tuning Power Scripts: With 100+ High Performance SQL Scripts”

So, what is wrong with the query? OK, the table aliases are inconsistent, but that is too easy. Let’s refer to the Oracle Database 11.2 documentation for the V$ACTIVE_SESSION_HISTORY view.

“V$ACTIVE_SESSION_HISTORY displays sampled session activity in the database. It contains snapshots of active database sessions taken once a second. A database session is considered active if it was on the CPU or was waiting for an event that didn’t belong to the Idle wait class. Refer to the V$EVENT_NAME view for more information on wait classes.

This view contains one row for each active session per sample and returns the latest session sample rows first. A majority of the columns describing the session in the active session history are present in the V$SESSION view.”

Still not seeing the problem? If we believe the documentation, assume that we are only interested in a 10 second time interval, and one of the sessions started waiting on a wait event at the start of the time interval, and was still waiting in the same wait event at the end of the 10 second time interval. SUM(A.WAIT_TIME + A.TIME_WAITED) for the session (assuming that rounding does not happen due to view update frequency) would show 1 + 2 + 3 + 4 + 5 + 6 + 7 + 8 + 9 + 10 = 55 seconds of total wait time for the result of the SUM function. Not too bad, right? Now, assume that the session had already waited 240 seconds and continued to wait for an additional 10 seconds – the SUM(A.WAIT_TIME + A.TIME_WAITED) for the session would show that the session waited 240 + 241 + 242 + 243 + 244 + 245 + 246 + 247 + 248 + 249 + 250 = 2695 seconds (44.92 minutes) in that 10 second time interval.

—

A fun little test that will require two sessions. In Session 1:

CREATE TABLE T1 (
  C1 NUMBER,
  PRIMARY KEY(C1));

INSERT INTO
  T1
VALUES (
  1);

Now, in Session 1, determine the SID:

COLUMN SID FORMAT 999

SELECT
  SID
FROM
  V$MYSTAT
WHERE
  ROWNUM=1;

 SID
----
 189

In Session 2, determine the SID:

COLUMN SID FORMAT 999

SELECT
  SID
FROM
  V$MYSTAT
WHERE
  ROWNUM=1;

 SID
----
   4

Back in Session 1, insert a row into the table:

INSERT INTO
  T1
VALUES (
  1);

In Session 2, attempt to insert the same row into the table (a primary key violation if the first session commits):

INSERT INTO
  T1
VALUES (
  1);

Session 2 is now hung. Back in Session 1, wait 20 minutes and check ~~AWR~~ ASH using a slightly fixed version of the query (mainly the table aliases are corrected, and adjusted to examine only the last 10 seconds of entries in V$ACTIVE_SESSION_HISTORY for the two sessions of interest):

SELECT
  A.CURRENT_OBJ#,
  D.OBJECT_NAME,
  D.OBJECT_TYPE,
  A.EVENT,
  SUM(A.WAIT_TIME + A.TIME_WAITED) TOTAL_WAIT_TIME
FROM
  V$ACTIVE_SESSION_HISTORY A,
  DBA_OBJECTS D
WHERE
  A.SAMPLE_TIME BETWEEN SYSDATE – 10/(24*60*60) AND SYSDATE
  AND A.CURRENT_OBJ# = D.OBJECT_ID
  AND A.SESSION_ID IN (4,189)
GROUP BY
  A.CURRENT_OBJ#,
  D.OBJECT_NAME,
  D.OBJECT_TYPE,
  A.EVENT
ORDER BY
  TOTAL_WAIT_TIME; 

no rows selected

That can’t be the expected result. Let’s try running the following query in Microsoft Excel:

SELECT
  SESSION_ID,
  EVENT,
  CURRENT_OBJ#,
  SAMPLE_TIME,
  WAIT_TIME,
  TIME_WAITED
FROM
  V$ACTIVE_SESSION_HISTORY
WHERE
  SESSION_ID IN (4,189)
ORDER BY
  SESSION_ID,
  SAMPLE_TIME;

After scrolling down a couple of thousand lines in the spreadsheet:

Well, that throws off the results of the query found in the book a bit. The CURRENT_OBJ# is -1 and the session has not waited any time (SUM(A.WAIT_TIME + A.TIME_WAITED) = 0 for SID 4, but would be 116,972,415 for SID 189 for the same CURRENT_OBJ# = -1).

Maybe the query found in the book just does not work for potential primary key violations? What about a case where one session updates a row and another session attempts to update the same row? Issue a COMMIT in Session 1 and Session 2. In Session 1:

COMMIT;

UPDATE
  T1
SET
  C1=C1;

In Session 2, attempt to update the same row:

UPDATE
  T1
SET
  C1=C1;

Session 2 is hung while waiting for Session 1 to COMMIT or ROLLBACK. Now wait for a while. While you are waiting, let’s take a quick look at the documentation for the V$ACTIVE_SESSION_HISTORY view from the 11.2 Oracle Documentation library:

“TIME_WAITED: If SESSION_STATE = WAITING, then the time that the session actually spent waiting for that event (in hundredths of a second). This column is set for waits that were in progress at the time the sample was taken.

If a wait event lasted for more than a second and was caught waiting in more than one session sample row, then the actual time spent waiting for that wait event will be populated in the last of those session sample rows.”

OK, must check the SESSION_STATE column, only the last of those sample rows in a string of rows for the same wait event, and the time is in 1/100th (0.01) of a second. Let’s re-run the query in Excel to see the progress:

That 2,471,728,088 number in the TIME_WAITED column appears to be in conflict with the description in the Oracle Documentation library – the time appears to be reported in 1/1,000,000 (0.000001) of a second, not 1/100 of a second.

—

Back to the original topic of this article. I have yet to determine why the query subtracts 30/2880 from the SYSDATE to retrieve the activity in the last 15 minutes – wouldn’t it be more clear to subtract 15 / (24 * 60) or 15 / 1440? Considering that the SAMPLE_TIME column in V$ACTIVE_SESSION_HISTORY is a TIMESTAMP datatype, would it make more sense to use SYSTIMESTAMP rather than SYSDATE?

Finally, What is Wrong with the Quote Found in the Book?

Comments : 16 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Addressing TM Enqueue Contention – What is Wrong with this Quote?

19 06 2011

June 19, 2011

Currently, the most viewed article in the past 90 days on this blog demonstrates a deadlock situation that is present in Oracle Database 11.1.0.6 and above that is not present in Oracle Database 10.2.0.1 through 10.2.0.5 (someone else might be able to check the earlier releases). This particular deadlock was the result of a missing foreign key index, which resulted in TM enqueues and an eventual deadlock when the first of three sessions issued a COMMIT. From this bit of information, hopefully it is clear that foreign key columns should usually be indexed (especially if the primary/unique column in in the parent table is subject to UPDATE statements).

While reading the alpha edition of the “Oracle Database 11g Performance Tuning Recipes” book, I noticed a test case in Recipe 5-15 that is intended to demonstrate how an index on a foreign key’s column(s) helps to resolve the most common cause of TM enqueues. While the test case included the DDL to create a parent and child table, it did not include the DML to create test data. The DDL for the two tables looks something like the following:

CREATE TABLE STORES (
  STORE_ID NUMBER(10) NOT NULL,
  SUPPLIER_NAME VARCHAR2(40) NOT NULL,
  CONSTRAINT STORES_PK PRIMARY KEY (STORE_ID));

CREATE TABLE PRODUCTS (
  PRODUCT_ID NUMBER(10) NOT NULL,
  PRODUCT_NAME VARCHAR2(30) NOT NULL,
  SUPPLIER_ID NUMBER(10) NOT NULL,
  STORE_ID NUMBER(10) NOT NULL,
  CONSTRAINT FK_STORES FOREIGN KEY (STORE_ID) REFERENCES STORES(STORE_ID) ON DELETE CASCADE);

Immediately after the above DDL statements appears the following claim is made by the alpha copy of the book:

“If you now delete any rows in the STORES table, you’ll notice waits due to locking.”

Interesting observation… I hope that the final copy of the book includes the DML to populate those tables. In the mean time, let’s create our own test data to see if the claim made in the quote is correct:

INSERT INTO
  STORES
SELECT
  ROWNUM STORE_ID,
  'SUPPLIER NAME '||TO_CHAR(ROWNUM) SUPPLIER_NAME
FROM
  DUAL
CONNECT BY
  LEVEL<=10;

INSERT INTO
  PRODUCTS
SELECT
  ROWNUM PRODUCT_ID,
  'PRODUCT NAME '||TO_CHAR(ROWNUM) PRODUCT_NAME,
  TRUNC((ROWNUM-1)/10)+100 SUPPLIER_ID,
  TRUNC((ROWNUM-1)/10)+1 STORE_ID
FROM
  DUAL
CONNECT BY
  LEVEL<=100;

COMMIT;

We now have 10 rows in the parent table and 100 rows in the child table (side note: is there something strange about the names of the columns in the tables?). Let’s connect to the database using two sessions. In Session 1, execute the following to delete a row from the STORES table:

DELETE FROM
  STORES
WHERE
  STORE_ID=1;

Here is the challenge, what happens if we attempt to execute the following script in Session 2 (the values to be inserted should not conflict with existing rows in the tables):

INSERT INTO
  STORES
SELECT
  ROWNUM+10 STORE_ID,
  'SUPPLIER NAME '||TO_CHAR(ROWNUM+10) SUPPLIER_NAME
FROM
  DUAL
CONNECT BY
  LEVEL<=10;

INSERT INTO
  PRODUCTS
SELECT
  ROWNUM PRODUCT_ID,
  'PRODUCT NAME '||TO_CHAR(ROWNUM+100) PRODUCT_NAME,
  TRUNC((ROWNUM+100-1)/10)+100 SUPPLIER_ID,
  TRUNC((ROWNUM+100-1)/10)+1 STORE_ID
FROM
  DUAL
CONNECT BY
  LEVEL<=100;

Which of the following will happen?

a. Session 2 will be blocked by session 1, with session 2 waiting in the “enq: TM – contention” wait event when it attempts to execute the first of the two SQL statements.

b. Session 2 will be blocked by session 1, with session 2 waiting in the “enq: TM – contention” wait event when it attempts to execute the second of the two SQL statements.

c. Session 2 will receive the following error message “ERROR at line 1: ORA-02291: integrity constraint (TESTUSER.FK_STORES) violated – parent key not found”.

d. Session 2 will corrupt the database due to the missed TM enqueue.

e. Session 2 will be waiting in the “SQL*Net message from client” wait event after it attempts to execute the second of the two SQL statements.

—–

Think about the above for a moment before scrolling down. Does the Oracle release version make a difference?

–

Now that you have thought about the question for a minute or two, take a look at the output I received on Oracle Database 11.2.0.2:

SQL> INSERT INTO
  2    STORES
  3  SELECT
  4    ROWNUM+10 STORE_ID,
  5    'SUPPLIER NAME '||TO_CHAR(ROWNUM+10) SUPPLIER_NAME
  6  FROM
  7    DUAL
  8  CONNECT BY
  9    LEVEL<=10;

10 rows created.

SQL> INSERT INTO
  2    PRODUCTS
  3  SELECT
  4    ROWNUM PRODUCT_ID,
  5    'PRODUCT NAME '||TO_CHAR(ROWNUM+100) PRODUCT_NAME,
  6    TRUNC((ROWNUM+100-1)/10)+100 SUPPLIER_ID,
  7    TRUNC((ROWNUM+100-1)/10)+1 STORE_ID
  8  FROM
  9    DUAL
 10  CONNECT BY
 11    LEVEL<=100;

100 rows created.

So, the answer to the multiple choice question is…

Wait… we are not done yet. Back in Session 2 execute the following which will delete a previously committed row (Session 1 previously deleted the row with STORE_ID=1, but has yet to COMMIT):

DELETE FROM
  STORES
WHERE
  STORE_ID=10;

The output I received on Oracle Database 11.2.0.2:

SQL> DELETE FROM
  2    STORES
  3  WHERE
  4    STORE_ID=10;

(session is hung - reporting wait event "enq: TM - contention")

So, the answer to the multiple choice question is… Wait, does the Oracle Database release version matter?

—

Comments : 3 Comments »

Categories : Quiz - Whose Answer is it Anyway?

Row Lock is Synonymous with TX Lock, and is a Lock on a Single Row of a Table – Verify the Documentation Challenge

10 06 2011

June 10, 2011

I found an interesting quote in the Oracle Database documentation library:

“Row Locks (TX)
A row lock, also called a TX lock, is a lock on a single row of a table. A transaction acquires a row lock for each row modified by one of the following statements: INSERT, UPDATE, DELETE, MERGE, and SELECT … FOR UPDATE. The row lock exists until the transaction commits or rolls back.

When a transaction obtains a row lock for a row, the transaction also acquires a table lock for the table in which the row resides. The table lock prevents conflicting DDL operations that would override data changes in a current transaction.

Table Locks (TM)
A transaction automatically acquires a table lock (TM lock) when a table is modified with the following statements: INSERT, UPDATE, DELETE, MERGE, and SELECT … FOR UPDATE. These DML operations require table locks to reserve DML access to the table on behalf of a transaction and to prevent DDL operations that would conflict with the transaction. You can explicitly obtain a table lock using the LOCK TABLE statement, as described in ‘Manual Data Locking‘.”

It appears that the above quote was changed a bit and included in section 5-11 of the alpha copy of the book that I am reading:

“Oracle uses two types of locks to prevent destructive behavior: exclusive and share locks… Row locks, indicated by the symbol TX, lock just a single row of table for each row that’ll be modified by a DML statement such as INSERT, UPDATE, and DELETE. This is true also for a MERGE or a SELECT … FOR UPDATE statement. The transaction that includes one of these statements grabs an exclusive row lock as well as a row share table lock.”

—

Something to think about: If a row lock is also called a TX lock, and it is a lock on a single row in a table, does that mean that one would expect to see 1,000 of these TX locks for a single session if that session modifies 1,000 rows in a single table? Or, might we expect to see only a single transaction lock (TX) for the session that modified 1,000 rows in a single table – that would indicate that a row lock is not synonymous with a TX lock. For that matter, what about the other types of TX enqueues?

—

Maybe it works as Tom Kyte states here:

“the TX is not a row lock, TM is the ‘row lock’ actually.”

The above is further explained in this exchange on the OTN forums between Tom Kyte and Mark Bobak.

—

Some additional clarification from the latest version of Tom Kyte’s book (also found in his much older “Expert One-On-One Oracle” book):

“Whereas we get only one TX lock per transaction, we can get as many TM locks as the objects we modify.”

Combining the above quote with the quote from the documentation, does that mean that a session can only lock a single row per transaction? 🙂

—

So, is the documentation correct? If not, how would you re-word what appears in the documentation? Keep in mind the sub-title of this blog:

“Stop, Think, … Understand“

Comments : 5 Comments »

Categories : Quiz - Whose Answer is it Anyway?

NOLOGGING Option and log file sync Waits – What is Wrong with this Quote?

8 06 2011

June 8, 2011

I have not had published a “What is Wrong with this Quote” blog article for a couple of months, so I thought that I would publish a few of those types of articles.

The first quote is from the Alpha copy of the book “Oracle 11g Performance Tuning Recipes”, recipe 5-7 Resolving Log File Sync Waits. As always, I try to minimize the amount of text that I post for a quote, but a sufficient amount so that the context of the quote is not completely lost. The quote:

“As the log file sync wait event is caused by contention caused by the LGWR process, see if you can use the NOLOGGING option to get rid of these waits. Of course, in a production system, you can’t use the NOLOGGING option when the database is processing user requests, so this option is of limited use in most cases.”

“Although the database automatically calculates the value of the log_io_size parameter, you can specify a value for it, by issuing a command such as the following:
SQL> alter system set "_log_io_size"=1024000 scope=spfile;

System altered.                                 "

What, if anything, is wrong with the above quote?

Hint for the first half of the quote: AskTom, Documentation
Hint for the second half of the quote: The scale for the _log_io_size parameter is NOT bytes. This article may also be helpful.

Comments : 12 Comments »

Categories : Quiz - Whose Answer is it Anyway?

V$SESSION’s ROW_WAIT_OBJ# Column Shows the DATA_OBJECT_ID – Verify the Documentation Challenge

7 06 2011

June 7, 2011

While reading through the alpha copy of a performance tuning book, I noticed a set of SQL statements that were identical to those found in the Oracle Database 11.2 Performance Tuning Guide. The set of SQL statements from the Performance Tuning Guide follow:

10.3.1.1 Causes
To determine the possible causes, first query V$SESSION to identify the value of ROW_WAIT_OBJ# when the session waits for buffer busy waits. For example:
SELECT row_wait_obj#
  FROM V$SESSION
 WHERE EVENT = 'buffer busy waits';
To identify the object and object type contended for, query DBA_OBJECTS using the value for ROW_WAIT_OBJ# that is returned from V$SESSION. For example:
SELECT owner, object_name, subobject_name, object_type
  FROM DBA_OBJECTS
 WHERE data_object_id = &row_wait_obj;

In an earlier article we found that V$SESSION’s ROW_WAIT_OBJ# column indicated the OBJECT_ID, not the DATA_OBJECT_ID of the object (as found in DBA_OBJECTS) and the same was true for the obj# entry found in a 10046 trace file. When you first create an index the OBJECT_ID and the DATA_OBJECT_ID values will be the same for the index, as displayed in DBA_OBJECTS. However, when you rebuild the index the DATA_OBJECT_ID value for the index will change while the OBJECT_ID value remains unchanged. Likewise, when you first create a table the OBJECT_ID and the DATA_OBJECT_ID values will be the same, as displayed in DBA_OBJECTS. If you TRUNCATE a table, the OBJECT_ID value will remain the same while the DATA_OBJECT_ID value for the table will change.

The challenge is to build a test case that either confirms or refutes the claim made by the Oracle Database Performance Tuning Guide. Possible references:

AskTom thread
Metalink (MOS) ID 15476.1 “FAQ about Detecting and Resolving Locking Conflicts”
Metalink (MOS) Doc ID 603661.1 “ORA-01410: Invalid Rowid When Using rowid Generated from V$Session and Dba_objects”
Another article found on this blog (take a look at the Other Resources links)

Comments : 10 Comments »

Categories : General Administration, Quiz - Whose Answer is it Anyway?

	Charles Hooper on Favorite Free Applications to…
	Zach on Favorite Free Applications to…
	Charles Hooper on Favorite Free Applications to…
	Zach on Favorite Free Applications to…
	Charles Hooper on Huge Presentation – Work…
	Dan on Huge Presentation – Work…
	Charles Hooper on Review of Synology DS415+, How…
	Matthias Clausen on Review of Synology DS415+, How…
	Charles Hooper on _SMALL_TABLE_THRESHOLD Paramet…
	mohd atif on _SMALL_TABLE_THRESHOLD Paramet…
	Charles Hooper on Free ANSI SQL to Oracle Specif…
	Kalin Agrawal on Free ANSI SQL to Oracle Specif…
	Charles Hooper on Large Page Support or Not…
	vaurob on Large Page Support or Not…
	Locating Oracle… on Finding a New Home for a Clien…

Charles Hooper's Oracle Notes

Histograms – What is Wrong with this Quote?

Temporary Tablespace Storage Parameters – What is Wrong with this Quote

Repeat After Me: NULL Values are Not Stored in Indexes?

Full Table Scans and the Buffer Cache in 11.2 – What is Wrong with this Quote?

Interesting Index “Facts” – What is Wrong with these Quotes?

Directly Executing a Query is Slower than Returning a REFCURSOR from a PL/SQL Procedure – What is Wrong with this Quote?

Tables and Their Indexes Should be Located on Different Disks – What is Wrong with this Quote?

Stored Outlines (Plan Stability) are an Enterprise Edition Feature? A Self-Conflicting Story

Using TKPROF for Analyzing 10046 Extended SQL Trace Files – What is Wrong with this Quote?

Inline Views – What is Wrong with this Quote?

10046 Extended SQL Tracing for a Session – What is Wrong with this Quote?

Unindexed Foreign Keys – What is Wrong with this Quote?

Parse CPU to Parse Elapsd – What is Wrong with this Quote?

KEEP Pool – What is Wrong with this Quote?

The CURSOR_SHARING Parameter is a Silver Bullet – What is Wrong with this Quote?

Find Objects with the Greatest Wait Time – What is Wrong with this Quote?

Addressing TM Enqueue Contention – What is Wrong with this Quote?

Row Lock is Synonymous with TX Lock, and is a Lock on a Single Row of a Table – Verify the Documentation Challenge

“Stop, Think, … Understand“

NOLOGGING Option and log file sync Waits – What is Wrong with this Quote?

V$SESSION’s ROW_WAIT_OBJ# Column Shows the DATA_OBJECT_ID – Verify the Documentation Challenge

Categories

Recent Articles

Misc. Articles

Popular Articles

Recent Comments

Blogroll

Hints for Posting Code Sections in Comments