Re: Tuning question - low cpu_time, high elapsed_time - what gives?

> "Steve B" <BigBoote66_at_hotmail.com> wrote in message
> news:67bcf80a.0410121254.4e553c81_at_posting.google.com...
> >
> > I have a few ideas as to what statements may be causing the problem -
> > even under "smooth sailing" time windows, I still see the total
> > "enqueue" time in the statspack report as showing up as a rather high
> > percentage of the time under the top 5 Timed Events (501 seconds in a
> > 10 minute period). Unfortunately, it may not be possible to deal with
> > them without a major system redesign. However, I'm curious regarding
> > this:
> >
> > I understand how DML can get blocked by another DML statement, but how
> > can a SELECT statement become blocked? We're not doing any logic
> > where we perform full table exclusive locks, and in experiments I've
> > done, updating a table with a bitmap index doesn't block another
> > session that is doing a select from that table.
>
> "Jonathan Lewis" <jonathan_at_jlcomp.demon.co.uk> wrote in message news:<ckicc7$4tk$1_at_hercules.btinternet.com>...
> Are you using distributed transactions to
> update the table ? (For a hint about
> the presence of distributed transactions
> look at v$enqueue_stats for enqueues
> of type 'DX').
>
> If so then a query had to wait for
> a distributed update to complete
> its two-phase commit if the query
> starts between the prepare and
> commit and visits a block modified
> by the distributed transaction.
>
> In times of high load (especially
> network load) this can slow things
> down considerably.

Unfortunately there are no DX enqueues in my system - we're not using distributed transactions, just a basic single server. The load on our Oracle box isn't particularly high either - pretty much a constant .9 on a 4-processor system.

I've been reading your "Practical Oracle" book and checking your website for some insight into tracking down the problem. Here's something I'm seeing when I run a version of your v$filestat query for a 10 minute window when we encountered this problem: (I'm using the STATS$FILESTATXS table out of statspack so that I can get a snapshot of activity during a timewindow instead of looking at the lifetime statistics - I assume the time numbers are in centiseconds):

TSNAME Reads Read Blocks Read Avg ------------- ---------- ----------- ----------

ARGUS              15757       32281 .658120201
ARGUS_INDEX         9673        9673 4.10348392
INDX                   1           1          3
SYSTEM               248         822 1.32258065
TOOLS                197         212 .680203046
UNDOTBS1              19          19 2.21052632
USERS                  1           1          3

Writes Write Blocks  Write Avg      Waits   Avg Wait
------ ------------ ---------- ---------- ----------
  1583         1583 477.664561         96 .729166667
  9023         9023 464.028815        164 29.8780488
     1            1          2          0          0
     9            9 785.666667          0          0
  1452         1452  466.12259          0          0
 11063        11063 797.981289        373 21.3672922
     1            1          5          0          0

Here is a 10 minute snap from a period where we had no problems:

TSNAME Reads Read Blocks Read Avg ------------- ---------- ----------- ----------

ARGUS               5758       19071 .856026398
ARGUS_INDEX         3144        3144 .847964377
INDX                   0           0          0
SYSTEM                 6           6          1
TOOLS                173         173 .537572254
UNDOTBS1               0           0          0
USERS                  0           0          0

Writes Write Blocks  Write Avg      Waits   Avg Wait
------ ------------ ---------- ---------- ----------
  1019         1019 389.111874        453 .682119205
  1020         1020 119.469608        101 .831683168
     0            0          0          0          0
     2            2        143          0          0
     0            0          0          0          0
   381          381 49.0892388         18 .166666667
     0            0          0          0          0

The most obvious thing that sticks out to me is that there was a lot of UNDO activity in the first snap. Could it be that the select statement that was getting blocked was having problems getting data from the undo tablespace while another transation was performing an update?

Thanks,
-Steve Received on Thu Oct 14 2004 - 13:06:59 CDT