Jonathan, as always, you are spot on.
The State is "WAITED SHORT TIME" and the wait_time is -1 always.
I then used Tanel Poder's waitprof.sql and the results are exactly as you
described them
% Total Total Event
Distinct Avg time
SID STATE EVENT P1 Time Time ms
Events ms/Event
------- ------- ----------------------- ----------- ------- ------------
---------- ----------
2543 WORKING On CPU / runqueue 94.35 68688.969
1542 44.545
2543 WAITING db file sequential read file#= 1397 1.26 914.783
285 3.210
2543 WAITING db file sequential read file#= 1461 1.04 757.193
298 2.541
2543 WAITING db file sequential read file#= 1554 1.02 742.909
275 2.701
2543 WAITING db file sequential read file#= 1431 .81 590.168
167 3.534
2543 WAITING db file sequential read file#= 1516 .81 589.651
225 2.621
2543 WAITING db file sequential read file#= 1532 .42 306.845
205 1.497
2543 WAITING db file sequential read file#= 1736 .25 180.449
78 2.313
2543 WAITING db file sequential read file#= 1393 .04 28.538
11 2.594
2543 WAITING db file sequential read file#= 69 .00 .495
1 .495
How do I see what's causing the On CPU / runqueue? I'm on Windows, so the
my normal searching google hasn't helped.
With a background job that flushes the buffer pool every 6 seconds, the
above stats change to the below where the time spent on CPU has gone to 6%.
89% is spent on DB file seq reads, which I assume are physical reads as I
just flushed the buffer_cache.
% Total Total Event
Distinct Avg time
SID STATE EVENT P1 Time Time ms
Events ms/Event
------- ------- ------------------------ ----------- ------- ------------
---------- ----------
2543 WAITING db file sequential read file#= 1397 16.71 10282.810
7338 1.401
2543 WAITING db file sequential read file#= 1736 16.67 10258.066
6949 1.476
2543 WAITING db file sequential read file#= 1532 12.81 7879.020
4484 1.757
2543 WAITING db file sequential read file#= 1431 12.61 7760.613
4550 1.706
2543 WAITING db file sequential read file#= 1461 12.05 7410.447
4816 1.539
2543 WAITING db file sequential read file#= 1554 11.10 6828.972
4870 1.402
2543 WAITING db file sequential read file#= 1516 10.74 6609.912
4760 1.389
2543 WORKING On CPU / runqueue 6.97 4290.829
37705 .114
2543 WAITING db file parallel read files= 6 .11 67.998
5 13.600
2543 WAITING db file parallel read files= 7 .04 25.758
4 6.440
2543 WAITING db file sequential read file#= 9 .04 22.215
14 1.587
2543 WAITING db file parallel read files= 5 .03 21.187
1 21.187
2543 WAITING db file parallel read files= 2 .03 18.776
3 6.259
2543 WAITING db file sequential read file#= 69 .03 17.398
4 4.349
2543 WAITING db file sequential read file#= 19 .02 11.258
8 1.407
2543 WAITING db file sequential read file#= 895 .02 9.714
16 .607
2543 WAITING db file parallel read files= 3 .01 4.608
4 1.152
2543 WAITING db file sequential read file#= 1393 .00 .418
1 .418
Regards, Jithin
On 2 March 2016 at 13:56, Jonathan Lewis <jonathan@xxxxxxxxxxxxxxxxxx>
wrote:
This means you spend some time waiting for a db file sequential read and
then spend 6 or 7 seconds on CPU.
The column seconds_in_wait would be better named "second since this wait
started" - you need to look at STATE and WAIT_TIME to find out if the
session is still waiting, and how long it waited for if it isn't.
Better still, look at v$session_wait_history to get information on the
last 10 waits for the session; even better - if you are licensed to view
v$active_session_history, check the per-second history for the session and
you'll probably get 6 or 7 explcit "ON CPU" rows for the time you've
interpreted as wait time.
Regards
Jonathan Lewis
http://jonathanlewis.wordpress.com
@jloracle
------------------------------
*From:* oracle-l-bounce@xxxxxxxxxxxxx [oracle-l-bounce@xxxxxxxxxxxxx] on
behalf of Jithin Sarath [jithinsarath@xxxxxxxxx]
*Sent:* 02 March 2016 07:18
*To:* oracle-l@xxxxxxxxxxxxx
*Subject:* db_file_sequential_reads takes over 7 seconds per seq# change
jump for single block read.
All, I have a strange problem and need guidance.
I support databases for Oracle E-Business Suite, and in one of our
production instances, a job is long running. This in itself is not new, but
what perplexes me is that when I look at v$session_waits for this session,
I see that the seconds_in_wait climbs to 6 or 7 per
db_file_sequential_read. Once it reached this situation, the seq# will
increment slowly as opposed to quick jumps in 1000s.
If I flush the buffer_cache, the processing speeds up and after a while it
hit the slow db_file_sequential_reads again. Other DB session do not show
this problem. I tried to dump the blocks that are referenced when it is
slow, and it points to one of the tow indexes. When I query the table
directly using the index, the results are quick. The execution plan doesn't
show any "outliers" and the expected execution is < 2 sections.
How do I explain this?
Thanks in advance, Jithin
