Re: long running select min(timestamp) query

From: Charles Hooper <hooperc2000_at_yahoo.com>
Date: Mon, 28 Jan 2008 18:37:37 -0800 (PST)
Message-ID: <ec1394ab-ba7d-40fb-8c79-c3ac9315455a@i29g2000prf.googlegroups.com>


Responses inline:

On Jan 28, 6:26 pm, "bobdu..._at_gmail.com" <bobdu..._at_gmail.com> wrote:
> On Jan 28, 11:39 am, Charles Hooper <hooperc2..._at_yahoo.com> wrote:
> > Try a simple test:
> > First, create a table with a single column and an index on that
> > column:
> > CREATE TABLE T1 (EVENTDATE TIMESTAMP NOT NULL);
> > CREATE INDEX T1_IND1 ON T1(EVENTDATE);
>
> > Now, insert 900,000 rows into the table, commit and gather table and
> > index stats:
> > INSERT INTO
> >   T1
> > SELECT
> >   TRUNC(SYSDATE-3000)+ROWNUM/100
> > FROM
> >   DUAL
> > CONNECT BY
> >   LEVEL<=900000;
>
> > COMMIT;
>
> > EXEC
> > DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE)
>
> > Finally, run a simple query:
> > SELECT
> >   MIN(EVENTDATE)
> > FROM
> >   T1;
>
> > From a 10046 trace, only 3 blocks read, all by consistent read:
> > EXEC #12:c=0,e=352,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=7550820123
> > FETCH #12:c=0,e=86,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,tim=7550820562
>
> > The DBMS XPLAN:
> > ---------------------------------------------------------------------------­---------------------
> > | Id  | Operation                  | Name    | Starts | E-Rows | A-
> > Rows |   A-Time   | Buffers |
> > ---------------------------------------------------------------------------­---------------------
> > |   1 |  SORT AGGREGATE            |         |      1 |      1 |
> > 1 |00:00:00.01 |       3 |
> > |   2 |   INDEX FULL SCAN (MIN/MAX)| T1_IND1 |      1 |    904K|
> > 1 |00:00:00.01 |       3 |
> > ---------------------------------------------------------------------------­---------------------
>
> > Does the above experiment execute quickly, and read only 3 blocks on
> > your system?
>
> I tried your experiment, and achieved similar responses - i'm a
> complete novice and don't know exactly how you got the 10046 trace
> output, but i did do the explain stuff:
>
> ---------------------------------------------------------------------------­-----------
> | Id  | Operation                  | Name    | Rows  | Bytes | Cost
> (%CPU)| Time     |
> ---------------------------------------------------------------------------­-----------
> |   0 | SELECT STATEMENT           |         |     1 |    11 |     3
> (0)| 00:00:01 |
> |   1 |  SORT AGGREGATE            |         |     1 |    11
> |            |          |
> |   2 |   INDEX FULL SCAN (MIN/MAX)| T1_IND1 |   901K|  9685K|     3
> (0)| 00:00:01 |
> ---------------------------------------------------------------------------­-----------
>
> I think this is comparable, but please advise if not.

What you posted above are the estimates, and do not include the actual execution statistics. But for this comparison, that will work just as well. See the following for an example of how to use DBMS_XPLAN to retrieve the actual execution statistics: http://jonathanlewis.wordpress.com/2006/11/09/dbms_xplan-in-10g/

Your explain plan (of my query example) above shows a prediction of 901K rows, while on my system Oracle was predicting 904K rows. My explain plan shows that the actual number of rows were 1, and that 3 buffers were used (the 10046 plan showed that these were consistent reads - logical in-memory reads). Your explain plan shows a cost of 3, implying that 3 blocks will be read.

Now, let's look at the explain plan that you posted for your original query and compare it to the explain plan that you posted of my query example:
736K rows predicted, with a cost of 4 - your query is expected to perform one more logical or physical read than my query example. This implies that your query should execute roughly as fast as my query example (in roughly 0.01 seconds or less).

To enable a 10046 trace for your session with wait events: ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 8'; To disable the trace for your session:
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT OFF'; You can find the trace file that is generated in the udump directory on the server. As you take a look at the 10046 trace files, you will see lines containing a series of values, such as:   c=0,e=352,p=0,cr=0,cu=0

The above reads as: 0 CPU seconds, 352/1000000 second elapsed time, 0 physical reads, 0 consistent reads (logical, in-memory), 0 current mode reads (similar to consistent reads, but typically more efficient).

You will likely also find various wait events which may help identify the source of any delays.

Please post a DBMS_XPLAN for your query using the technique described on the above link.

Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc. Received on Mon Jan 28 2008 - 20:37:37 CST

Original text of this message