Re: Enqueue and DB File Sequential Read Waits Problem

Oracle waits normally 3 seconds on a TX enqueue, checks for interrupts and goes again to sleep for 3 seconds. So if we see 307 on average, we waited longer. Now there may be tons of reasons of why that is: scheduling, granularity, etc. The thing to know/remember is that an enqueue wait is counted differently in different parts of the Oracle kernel. You can check for the session in v$sesstat (where name or stat# = 'enqueue waits') that will tell you how often the session waited for an enqueue. So take the wait time from v$session_event for enqueue and divide that by enqueue waits (v$sesstat) and you have the average enqueue wait time.

If we can't trust the timing on NT we probably need a tool that samples more precisely ;-)

Anjo.

Jonathan Lewis wrote:

> Regarding the Enqueues:
> One follow-up is to connect as SYS and look at
> x$ksqst where ksqstwat != 0. This tells you two
> things (after the event). First, which type of
> enqueue has suffered waits, and secondly whether
> the waits in v$session_wait are represent a few
> very long waits or lots of shorter waits.
> (v$session_wait increments every 3 seconds,
> x$ksqst just once at the end)
>
> However, since your wait time is a large fraction
> of your elapsed time, you will probably be able to
> get some extra information simply by running a query
> against v$session_wait where name = 'enqueue' a
> couple of dozen times in quick succession.
> For the same reason, if you look at v$lock where
> request != 0 at regular intervals, you will be able to
> see the type and id of the wait.
>
> If you can identify the enqueue type, request mode,
> and id values, then you can track down causes more
> easily.
>
> Regarding the db file sequential read:
> Can I confirm that your report is describing a job
> where your session runs for six hours, and reports
> 1 hour of enqueues, and 4 hours of db file sequential
> reads, in that six hours ?
>
> If that is the case, then even though the reads are
> very fast reads (presumably helped by a large file-system
> buffer) then I suspect your SQL (or the strategy surrounding
> your use of SQL) needs to be examined. You MAY be doing
> an extreme amount of logical I/O to require 7M single block
> reads for one (effective) hour of CPU usage.
>
> For example, it is possible that the code has been 'tuned'
> to eliminate tablescans and increase hit ratios, with the
> detrimental side-effect that the logical I/O has gone up
> dramatically, and increased the actual cost of physical
> I/O. It is possible that the code has been written to loop
> through cursors and 'emulate' joining by executing several
> simple statements per row of the main cursor.
>
> In the short term, you may get an improvement in
> performance by shifting memory away from the
> file system buffer and into the Oracle buffer.
> The logical I/O won't drop, but the number of waits
> for filesystem interaction may.
>
> Anjo, the 307 is interesting. I have seen 307 and 107
> (depending on wait event) appear as the max time with
> remarkable frequency on Windows systems, even when
> the machines were idle. I wonder if this may be due to
> some tick-granularity on Windows/DOS-based machines,
> rather than stress. (In fact, the first time I saw this was
> on a Sun that was under extreme pressure, and I made
> the same assumption that you did - now I'm beginning
> to wonder if there is more to it than that).
>
> Jonathan Lewis
> http://www.jlcomp.demon.co.uk
>
> Author of:
> Practical Oracle 8i: Building Efficient Databases
>
> Next Seminar - Australia - July/August
> http://www.jlcomp.demon.co.uk/seminar.html
>
> Host to The Co-Operative Oracle Users' FAQ
> http://www.jlcomp.demon.co.uk/faq/ind_faq.html
>
> -----Original Message-----
>
> |The enqueue problem looks like an TX enqueue problem. Given the fact
> that the
> |average wait is 307 and max wait is 308,
> |I can see that you are also running out of CPU on your box. The
> normal max_wait
> |should be 300 and the average wait should be less than 300.
>
> |
> |Sam Bootsma wrote:
> |
> |> We have a batch job taking a long time to process. Querying the
> |> v$session_wait view, I discovered there have been over 1200 enqueue
> waits,
> |> with an average wait of just over 307 and a max wait of 308. The
> total time
> |> waited is 370081 (just over one hour if these figures are in
> centiseconds).
> |> The batch job has been running about 6 hours.
> |>
> |> I also see that db file sequential read has waited almost 4 hours.
> This
> |> sounds like 4 hours waiting on index access requests. What could
> cause
> |> these long waits?
> |>
> |> I am not sure how to troubleshoot this problem further (Reading the
> |> Performance 101 Book is on My To Do List). This is Oracle 81630 on
> Windows
> |> NT server.
> |>
> |> Any suggestions or advice on how to troubleshoot this further is
> much
> |> appreciated. Here is my query and the output:
> |>
> |> SQL> l
> |> 1 select substr(event, 1,30), total_waits, time_waited,
> average_wait,
> |> max_wait
> |> 2 from v$session_event
> |> 3* where sid=18
> |> SQL> /
> |>
> |> SUBSTR(EVENT,1,30) TOTAL_WAITS TIME_WAITED
> AVERAGE_WAIT
> |> MAX_WAIT
> |> ------------------------------ ----------------------
> |> -------------------- -----------------------
> |> ---------------------
> |> latch free 5 0
> |> 0 0
> |> enqueue 1204 370081
> |> 307.376246 308
> |> buffer busy waits 45 0
> |> 0 0
> |> log file switch completion 2 27
> 13.5
> |> 17
> |> log file sync 4 0
> |> 0 0
> |> db file sequential read 7269278 1375000
> |> .18915221 29
> |> direct path read 4
> 10
> |> 2.5 10
> |> direct path write 1098 112
> |> .102003643 2
> |> file open 4 0
> |> 0 0
> |> SQL*Net message to client 555 0 0
> |> 0
> |> SQL*Net more data to client 11 1
> .090909091
> |> 1
> |> SQL*Net message from client 555 3256
> 5.86666667
> |> 1038
> |>
> |> Thanks again for any pointers and suggestions.
> |>
> |> Sam Bootsma, OCP
> |> Technical Support Analyst
> |
>
> --
> Please see the official ORACLE-L FAQ: http://www.orafaq.com
> --
> Author: Jonathan Lewis
> INET: jonathan_at_jlcomp.demon.co.uk
>
> Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
> San Diego, California -- Public Internet access / Mailing Lists
> --------------------------------------------------------------------
> To REMOVE yourself from this mailing list, send an E-Mail message
> to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
> the message BODY, include a line containing: UNSUB ORACLE-L
> (or the name of mailing list you want to be removed from). You may
> also send the HELP command for other information (like subscribing).

-- 
Please see the official ORACLE-L FAQ: http://www.orafaq.com
-- 
Author: Anjo Kolk
  INET: anjo_at_oraperf.com

Fat City Network Services    -- (858) 538-5051  FAX: (858) 538-5051
San Diego, California        -- Public Internet access / Mailing Lists
--------------------------------------------------------------------
To REMOVE yourself from this mailing list, send an E-Mail message
to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from).  You may
also send the HELP command for other information (like subscribing).