Re: High buffer gets

From: Tim Gorman <>
Date: Fri, 03 Feb 2012 18:25:25 +0000
Message-ID: <W9312726932239711328293525_at_webmail105>

If you look at the execution plan information you've provided, a clue is staring you in the face. Look at the row count for the INDEX RANGE SCAN on the index MTL_ONHAND_QUANTITIES_N5, which is 203,798. Then look at the row-count on the next step in the execution plan, which is TABLE ACCESS BY ROWID on MTL_ONHAND_QUANTITIES_DETAIL for 1 row. So, the query scanned over 200k index entries to find one row. That can't be good, can it?

Consider looking at all the indexes on that table, and seeing which of the other indexes might be used by this query. Chances are excellent that your most recent stats-regather caused the execution plan to change indexes, and for that reason, your query is now having problems.

To determine this, feel free to download the SQL*Plus script "sqlhistory.sql" (at ""), which will display the recent history of a SQL statement identified by it's SQL_ID. SQL tracing and TKPROF don't display SQL_ID, so you'll have to find it another way, such as searching through DBA_HIST_SQLTEXT. But information captured in AWR and displayed using "sqlhistory.sql" should show you when the execution plan changed.

Hope this helps...

Tim Gorman
consultant => Evergreen Database Technologies, Inc. postal => PO Box 352151, Westminster CO 80035 email =>
mobile => +1-303-885-4526
fax => +1-303-484-3608
Lost Data? => for info about DUDE... -----Original Message-----
From: Hameed, Amir [] Sent: Friday, February 3, 2012 10:26 AM
To: 'John Clarke', Subject: RE: High buffer gets

We run statistics on schemas as shown below:- Once a week on ALL schemas- Daily on the custom schema On this particular table, gather statistic was run on 30-JAN-2012 andthe job ran longer on 31-JAN-2012 and 01-FEB-2012. The explain plan forthis statement is:Rows Row Source Operation------- --------------------------------------------------- 1 FOR UPDATE (cr7248 pr#51 pw=0 time=0 us) 2 SORT ORDER BY (cr7248 pr#51 pw=0 time=0 us cost=9 size!6card=2) 1 CONCATENATION (cr7248 pr#51 pw=0 time=0 us) 0 FILTER (cr=0 pr=0 pw=0 time=0 us) 0 TABLE ACCESS BY INDEX ROWID MTL_ONHAND_QUANTITIES_DETAIL(cr=0 pr=0 pw=0 time=0 us cost=4 size 8 card=1) 0 INDEX RANGE SCAN MTL_ONHAND_QUANTITIES_N5 (cr=0 pr=0 pw=0time=0 us cost=3 size=0 card=1)(object id 402327) 1 FILTER (cr7248 pr#51 pw=0 time=0 us) 1 TABLE ACCESS BY INDEX ROWID MTL_ONHAND_QUANTITIES_DETAIL(cr7248 pr#51 pw=0 time=0 us cost=4 size 8 card=1)203798 INDEX RANGE SCAN MTL_ONHAND_QUANTITIES_N5 (cr 00 pr=0pw=0 time=0 us cost=3 size=0 card
 =1)(object id 402327) AmirFrom: John Clarke [] Sent: Friday, February 03, 2012 12:21 PMTo: Hameed, Amir; oracle-l_at_freelists.orgSubject: Re: High buffer gets Without seeing any SQL statements or execution plans, I'd probably guessit's statistics-related (i.e., they're out-of-date, missing, etc).Difficult to say though without seeing more of the trace file. - John From: "Hameed, Amir" Reply-To: "" Date: Fri, 3 Feb 2012 11:31:46 -0500To: "" Subject: High buffer gets Folks,We have an Oracle ERP system (11.5.10) with database version on Solaris 9. There are batch jobs, submitted via concurrentmanagers, that have been running fine for a long time. About two weeksago, we went through a release cycle where new code and functionalitywas introduced into this environment and since then some of the criticaljobs that have been running fine are now running longer most of thetimes. We have taken trace
 s of jobs and the one thing that is common toall of them is the sheer number of buffer gets from consistent reads. Iam pasting statistics from one such job below. This is from a standardOracle code. The obj# from the raw trace file showed an INVENTORY tablethat is updated heavily by the application in general. An interestingobservation is that this particular job runs fine on days when theinventory table is not heavily updated concurrently by the other jobs,introduced by the new code, that run when this job runs longer. But thisbehavior is not just limited to this job as there are other criticaljobs that have also started to show the same behavior all of a sudden. call count cpu elapsed disk query currentrows ------- ------ -------- ---------- ---------- ---------- -------------------- Parse 1 0.00 0.00 0 0 00 Execute 7811 8711.44 8501.30 14964 294967869 971220 Fetch 7811 0.61 0.61 0 0 049048 ------- ------ -------- ---------- ---------- ---------- -------------------- total
  15623 8712.05 8501.92 14964 294967869 9712249048 Has anyone seen this type of behavior? We are going to open an SR withOracle to see if we are hitting some type of bug here. Any feedback willbe appreciated. Thanks Amir -- --
Received on Fri Feb 03 2012 - 12:25:25 CST

Original text of this message