Re: long running select min(timestamp) query

From: <fitzjarrell_at_cox.net>
Date: Tue, 29 Jan 2008 09:34:02 -0800 (PST)
Message-ID: <7135cc70-8009-4f66-aad1-9a1aa244197f@v46g2000hsv.googlegroups.com>


Comments embedded.

On Jan 28, 5:26 pm, "bobdu..._at_gmail.com" <bobdu..._at_gmail.com> wrote:
> On Jan 28, 11:39 am, Charles Hooper <hooperc2..._at_yahoo.com> wrote:
>
>
>
>
>
> > On Jan 28, 10:40 am, "bobdu..._at_gmail.com" <bobdu..._at_gmail.com> wrote:
>
> > > Hi,
>
> > > I have a basic event table in my 10g database, primary integer key,
> > > and a nonnull timestamp "eventdate" field.  When executing the
> > > following command:
>
> > > select min(eventdate) from events;
>
> > > It can occasionally take a VERY long time.  There is a standard btree
> > > index on "eventdate", and roughly 20 other columns, a few of which
> > > also have basic btree indexes.
>
> > > In my current scenario, the table has less than a million records, and
> > > the query seems to be taking upwards of 10 minutes!!!  Here's what the
> > > console says the plan is:
>
> > > Operation       Object  Object Type     Order   Rows    Size (KB)       Cost    Time (sec)      CPU
> > > Cost    I/O Cost
> > > SELECT STATEMENT                        3                               4
> > >  SORT AGGREGATE                         2       1       0.011
> > >   INDEX FULL SCAN (MIN/MAX) EVENTS_EVENTDATE    INDEX   1       736195  7,908.345
> > > 4       1       28686   4
>
> > > I've run the ADDM, it updated the stats, but that doesn't seem to help
> > > (i run it again it has no recommendations).  Am i doing something
> > > silly with this table or is there some better way for me to phrase
> > > this query?
>
> > > Thanks,
> > > Bob
>
> > 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?
>
> > Charles Hooper
> > IT Manager/Oracle DBA
> > K&M Machine-Fabricating, Inc.
>
> Thank you for your replies, i'll do this one first.
>
> 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.
>
> 2nd question - my oracle web console tells me i'm running 10.2.0.1.0.
> I attempted to enable the plustrace role, and do as suggested, here's
> what i got:
>
> SQL> select min(eventdate) from events;
>
> MIN(EVENTDATE)
> ---------------------------------------------------------------------------
> 21-JAN-08 04.51.45.525000 PM
>
> Execution Plan
> ----------------------------------------------------------
> Plan hash value: 116994577
>
> ---------------------------------------------------------------------------­-----
>
> -----------------
>
> | Id  | Operation                  | Name               | Rows  |
> Bytes | Cost (
>
> %CPU)| Time     |
>
> ---------------------------------------------------------------------------­-----
>
> -----------------
>
> |   0 | SELECT STATEMENT           |                    |     1 |
> 11 |     4
>   (0)| 00:00:01 |
>
> |   1 |  SORT AGGREGATE            |                    |     1 |
> 11 |
>      |          |
>
> |   2 |   INDEX FULL SCAN (MIN/MAX)| EVENTS_EVENTDATE |   736K|
> 7908K|     4
>   (0)| 00:00:01 |
>
> ---------------------------------------------------------------------------­-----
>
> -----------------
>
> Statistics
> ----------------------------------------------------------
>         901  recursive calls
>           0  db block gets
>      118525  consistent gets
>      118248  physical reads
>           0  redo size
>         424  bytes sent via SQL*Net to client
>         381  bytes received via SQL*Net from client
>           2  SQL*Net roundtrips to/from client
>          18  sorts (memory)
>           0  sorts (disk)
>           1  rows processed
>

118525 consistent gets and 118248 physical reads to return one row from an index full scan is a bit much, I think, and explains why this is taking so long to complete. You've hit the buffer cache for 118525 blocks, and you've also loaded the buffer cache with 118248 blocks from disk; this is a lot of I/O in my opinion. Reducing this is the goal in my estimation, as it should then speed up the query (wading through less data gets you through the 'swamp' faster).

You may be experiencing the effects of row migration, where one data row has two or more 'pointers' because it's been relocated one or more times due to block space issues.
Creating the CHAINED_ROWS table ($ORACLE_HOME/rdbms/admin/ utlchain.sql) and running

analyze table events list chained rows;

would populate the CHAINED_ROWS table and could provide some additional information. Querying CHAINED_ROWS:

select owner_name, table_name, count(*)
from chained_rows
group by owner_name, table_name;

You may have nothing returned, or you may have a large number of chained/migrated rows with which to deal. Looking at your table definition and presuming an 8k block size I can't expect you'd have any actual chained rows (rows that, no matter what, will not fit into a single data block), but I can expect you may have any number of migrated rows, which can be fixed by increasing the PCTFREE for the table (currently set at 10). An alter table events move pctfree 25; could fix the migrated row issue and may improve your query response time. Notice I said 'may'; nothing, including the advice offered here, is guaranteed. You can see if the migrated rows are fixed by truncating the CHAINED_ROWS table and executing the same analyze table statement as before:

analyze table events list chained rows;

Hopefully if you had any migrated rows before they would now be gone. Executing your query against the now cleansed' table might show different statistics through autotrace. And those statistics might be an improvement over the original run. And again, this is somewhat guesswork.

> Does this explain anything?  Here's the same output using the "new"
> table, which for whatever reason is much better:
> SQL> select min(eventdate) from t1;
>
> MIN(EVENTDATE)
> ---------------------------------------------------------------------------
> 11-NOV-99 12.14.24.000000 AM
>
> Execution Plan
> ----------------------------------------------------------
> Plan hash value: 3630964933
>
> ---------------------------------------------------------------------------­-----
>
> ------
>
> | Id  | Operation                  | Name    | Rows  | Bytes | Cost
> (%CPU)| Time
>
>      |
>
> ---------------------------------------------------------------------------­-----
>
> ------
>
> |   0 | SELECT STATEMENT           |         |     1 |    11 |     3
> (0)| 00:0
>
> 0:01 |
>
> |   1 |  SORT AGGREGATE            |         |     1 |    11
> |            |
>      |
>
> |   2 |   INDEX FULL SCAN (MIN/MAX)| T1_IND1 |   901K|  9685K|     3
> (0)| 00:0
>
> 0:01 |
>
> ---------------------------------------------------------------------------­-----
>
> ------
>
> Statistics
> ----------------------------------------------------------
>         676  recursive calls
>           0  db block gets
>         132  consistent gets
>           6  physical reads
>           0  redo size
>         422  bytes sent via SQL*Net to client
>         381  bytes received via SQL*Net from client
>           2  SQL*Net roundtrips to/from client
>          22  sorts (memory)
>           0  sorts (disk)
>           1  rows processed

Here you have a completely different story: 132 blocks read from the buffer cache and 6 reads from disk to help populate the buffer cache. Of course thisis on your single-column table, but the response should be similar (depending upon your data) for your events table. You generate the same type of execution plan (INDEX FULL SCAN) yet the index for the EVENTS table is undergoing a tremendous amount of I/ O to return your single-row result.

I'll ask if the statistics for the EVENTS table are computed or estimated? Sometimes estimating statistics can 'overlook' anomolies in the data distribution (depending upon the percent of the data is used for the estimate) that computing would reveal. There are many other areas which could be affecting this query (although you are ending up with an index full scan as an access path). Not knowing the data is a hindrance when offering suggestions for improvement.

>
> The data in my table is likely mucked up in some capacity,

And, on the surface of it, I tend to agree.

> i just
> don't know what to do to fix it.
>

You will when/if you find out how it's 'mucked up'. You have some suggestions here, and others may be in order depending upon the state of your data.

> I will definitely get that book.  I'm new to all this, so any
> obligatory text's you can recommend i'll be all over.
>
> Thanks!- Hide quoted text -
>
> - Show quoted text -

David Fitzjarrell Received on Tue Jan 29 2008 - 11:34:02 CST

Original text of this message