Re: resolving buffer busy waits

From: Casey <cdyke_at_corp.home.nl>
Date: 17 Sep 2003 11:10:06 -0700
Message-ID: <8bc6b8d7.0309171010.26939c34@posting.google.com>

had wanted to get this posted earlier yesterday but am stuck in turbo mode both in and out of work ... ho hum ...

here's what i can add, some new, some in response to others:

highest %b max for any disk during recent peak = 62, ascv_t max 13 ...
iostat from top constantly around 35% mark
"striping" comment in earlier post was poor language choice on my behalf. suffice to say datafiles and archive share the same spindles
UFS optimisation "choices" (whatever they may be) were known such that we moved on that quickly
database block size 8k, os 8k
been running statspack reports for data dating back to the beginning of the year, no FTS in the mix, a few index range scans on horribly bloated indexes, but no "bad" sql (unless statspack and v$sql are hiding them from me)
index bloat is a problem, but the queries using them return sub-second
all redundant processing (garbage collection processes for example) have been ceased, so we have the app in all its glory churning away now
but the wait times still persist

did drill down into v$session_wait and that has helped explain the initial subject of this message:

first a session enters into a wait on db file sequential read for a block in datafile {x} (10 actually)
then another session comes along, then another ...
somewhere in the mix a bbw will occur, so i'll see a block w/a max seconds_in_wait for dfsr (db file sequential read), then followed by the bbw time
so the read is the crappy bit, bbw's are a manifestation of the read "problem" and tuning them -- as jonathan and i think nuno pointed out -- isn't the way to go.

so we have at peak times up to 700 odd active transactions. in my watching, i have seen the wait stack grow, at times, up to 500+ sessions, all just sitting and waiting on dfsr for various blocks in the same datafile.

and that explains the massive wait times. everyone just queues up, something "completes", all the waiting processes do so likewise w/the snap of a finger and then the problem pretty much immediately resurfaces and the waits/sessions waiting stack up again. very cyclical.

a recent cycle ended up w/132 sessions queueing, max seconds_in_wait 809, then the "complete" (for lack of a better term) occurred, then 84 queued up for a max of 90, then another group of 27 for a max wait of 21.

oh bugger. so the cyclic nature isn't necessarily long.

think i need a fresh set of eyes !!

the following is a slice of tkprof output for a 10046 trace for one of the queued sessions. total trace time was exactly 28 minutes.

call     count       cpu    elapsed       disk      query    current  
     rows

------- ------ -------- ---------- ---------- ---------- ----------

Parse       21      0.00       0.00          0          0          0  
        0
Execute     47      0.00       0.01          0          0          0  
        0
Fetch       78      0.11    1405.74        164       1118          0  
      391

------- ------ -------- ---------- ---------- ---------- ----------

total      146      0.11    1405.75        164       1118          0  
      391

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 24

Rows Row Source Operation

-------  ---------------------------------------------------

162 NESTED LOOPS
167 TABLE ACCESS BY INDEX ROWID {table 1} 167 INDEX RANGE SCAN (object id 3020) 162 TABLE ACCESS BY USER ROWID {table 2}

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current  
     rows

------- ------ -------- ---------- ---------- ---------- ----------

Parse      440      0.15       0.13          0          2          0  
        0
Execute   1186      1.64      11.98         73       2662       2316  
      381
Fetch      872      0.16    1446.98        180       4416         84  
     1363

------- ------ -------- ---------- ---------- ---------- ----------

total     2498      1.95    1459.09        253       7080       2400  
     1744

Received on Wed Sep 17 2003 - 13:10:06 CDT