Skip to Main Content
  • Questions

  • High number of buffers to get one block

Breadcrumb

Question and Answer

Connor McDonald

Thanks for the question, Matthew.

Asked: August 30, 2016 - 7:41 pm UTC

Last updated: September 05, 2016 - 4:22 pm UTC

Version: 12.1

Viewed 1000+ times

You Asked

I have a query who's DBMS_XPLAN output looks like this:

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                       | Name                         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                                |                              |      1 |        |      7 |00:00:00.17 |     310 |      7 |       |       |          |
|   1 |  HASH UNIQUE                                    |                              |      1 |     17 |      7 |00:00:00.17 |     310 |      7 |  1394K|  1394K|  865K (0)|
|*  2 |   HASH JOIN OUTER                               |                              |      1 |     17 |      7 |00:00:00.17 |     310 |      7 |  1055K|  1055K|  536K (0)|
|   3 |    NESTED LOOPS OUTER                           |                              |      1 |     17 |      7 |00:00:00.16 |     300 |      7 |       |       |          |
|   4 |     NESTED LOOPS OUTER                          |                              |      1 |     17 |      7 |00:00:00.01 |     283 |      0 |       |       |          |
|   5 |      NESTED LOOPS                               |                              |      1 |     17 |      7 |00:00:00.01 |     267 |      0 |       |       |          |
|   6 |       NESTED LOOPS OUTER                        |                              |      1 |     90 |      7 |00:00:00.01 |     244 |      0 |       |       |          |
|   7 |        NESTED LOOPS OUTER                       |                              |      1 |      6 |      5 |00:00:00.01 |     237 |      0 |       |       |          |
|   8 |         MERGE JOIN CARTESIAN                    |                              |      1 |      6 |      5 |00:00:00.01 |     233 |      0 |       |       |          |
|   9 |          NESTED LOOPS                           |                              |      1 |      1 |      1 |00:00:00.01 |     229 |      0 |       |       |          |
|  10 |           TABLE ACCESS BY INDEX ROWID           | VERP_OTM_STAGED_VONS         |      1 |      1 |      1 |00:00:00.01 |     228 |      0 |       |       |          |
|* 11 |            INDEX UNIQUE SCAN                    | VERP_OTM_STAGED_VONS_U2      |      1 |      1 |      1 |00:00:00.01 |       2 |      0 |       |       |          |
|* 12 |           INDEX FULL SCAN                       | VERP_VPS_SUPPLY_MP_N1        |      1 |      1 |      1 |00:00:00.01 |       1 |      0 |       |       |          |
|  13 |          BUFFER SORT                            |                              |      1 |      6 |      5 |00:00:00.01 |       4 |      0 |  2048 |  2048 | 2048  (0)|
|  14 |           VIEW                                  |                              |      1 |      6 |      5 |00:00:00.01 |       4 |      0 |       |       |          |
|  15 |            UNION-ALL                            |                              |      1 |        |      5 |00:00:00.01 |       4 |      0 |       |       |          |
|* 16 |             FILTER                              |                              |      1 |        |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|  17 |              TABLE ACCESS BY INDEX ROWID BATCHED| OE_ORDER_LINES_ALL           |      0 |     28 |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|* 18 |               INDEX RANGE SCAN                  | VERP_OE_ORDER_LINES_N1       |      0 |      7 |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|* 19 |             TABLE ACCESS BY INDEX ROWID BATCHED | VERP_ORDER_STD_ACCY_LINES    |      1 |      5 |      5 |00:00:00.01 |       4 |      0 |       |       |          |
|* 20 |              INDEX RANGE SCAN                   | VERP_ORDER_STD_ACCY_LINES_N1 |      1 |      5 |      5 |00:00:00.01 |       3 |      0 |       |       |          |
|  21 |         VIEW PUSHED PREDICATE                   | BOM_BILL_OF_MATERIALS        |      5 |      1 |      1 |00:00:00.01 |       4 |      0 |       |       |          |
|* 22 |          FILTER                                 |                              |      5 |        |      1 |00:00:00.01 |       4 |      0 |       |       |          |
|* 23 |           TABLE ACCESS BY INDEX ROWID BATCHED   | BOM_STRUCTURES_B             |      1 |      1 |      1 |00:00:00.01 |       4 |      0 |       |       |          |
|* 24 |            INDEX RANGE SCAN                     | BOM_STRUCTURES_B_N2          |      1 |      1 |      1 |00:00:00.01 |       3 |      0 |       |       |          |
|* 25 |        TABLE ACCESS BY INDEX ROWID BATCHED      | BOM_COMPONENTS_B             |      5 |     15 |      3 |00:00:00.01 |       7 |      0 |       |       |          |
|* 26 |         INDEX RANGE SCAN                        | BOM_COMPONENTS_B_N2          |      5 |     15 |      5 |00:00:00.01 |       4 |      0 |       |       |          |
|  27 |       TABLE ACCESS BY INDEX ROWID               | MTL_SYSTEM_ITEMS_B           |      7 |      1 |      7 |00:00:00.01 |      23 |      0 |       |       |          |
|* 28 |        INDEX UNIQUE SCAN                        | MTL_SYSTEM_ITEMS_B_U1        |      7 |      1 |      7 |00:00:00.01 |      16 |      0 |       |       |          |
|  29 |      TABLE ACCESS BY INDEX ROWID BATCHED        | BOM_STANDARD_OPERATIONS      |      7 |      1 |      7 |00:00:00.01 |      16 |      0 |       |       |          |
|* 30 |       INDEX RANGE SCAN                          | BOM_STANDARD_OPERATIONS_U1   |      7 |      1 |      7 |00:00:00.01 |       9 |      0 |       |       |          |
|  31 |     TABLE ACCESS BY INDEX ROWID BATCHED         | BOM_STD_OP_RESOURCES         |      7 |      1 |      7 |00:00:00.16 |      17 |      7 |       |       |          |
|* 32 |      INDEX RANGE SCAN                           | BOM_STD_OP_RESOURCES_U1      |      7 |      1 |      7 |00:00:00.16 |      10 |      7 |       |       |          |
|* 33 |    VIEW                                         | index$_join$_020             |      1 |      4 |     23 |00:00:00.01 |      10 |      0 |       |       |          |
|* 34 |     HASH JOIN                                   |                              |      1 |        |     23 |00:00:00.01 |      10 |      0 |  1393K|  1393K| 1455K (0)|
|* 35 |      INDEX FAST FULL SCAN                       | BOM_RESOURCES_U1             |      1 |      4 |     23 |00:00:00.01 |       6 |      0 |       |       |          |
|  36 |      INDEX FAST FULL SCAN                       | BOM_RESOURCES_U2             |      1 |      4 |    378 |00:00:00.01 |       4 |      0 |       |       |          |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   2 - access("BR"."RESOURCE_ID"="BSOR"."RESOURCE_ID")
  11 - access("V"."HEADER_ID"=:B1)
  12 - access("MP"."ORGANIZATION_CODE"="V"."PORT")
       filter("MP"."ORGANIZATION_CODE"="V"."PORT")
  16 - filter(NULL IS NOT NULL)
  18 - access("HEADER_ID"=:B1)
       filter(("ITEM_TYPE_CODE"='CLASS' OR "ITEM_TYPE_CODE"='OPTION'))
  19 - filter(("VOSAL"."ITEM_TYPE_CODE"='CLASS' OR "VOSAL"."ITEM_TYPE_CODE"='OPTION'))
  20 - access("VOSAL"."HEADER_ID"=:B1)
  22 - filter('CLASS'="OEL"."ITEM_TYPE_CODE")
  23 - filter(((("FND_GLOBAL"."RESP_APPL_ID"()<>431 AND NVL("EFFECTIVITY_CONTROL",1)<=3) OR "FND_GLOBAL"."RESP_APPL_ID"()=431 OR "FND_GLOBAL"."RESP_APPL_ID"()=(-1)) 
              AND "OBJ_NAME" IS NULL))
  24 - access("ASSEMBLY_ITEM_ID"="OEL"."INVENTORY_ITEM_ID" AND "ORGANIZATION_ID"=92)
  25 - filter((NVL("DISABLE_DATE",SYSDATE@!+1)>SYSDATE@! AND "OBJ_NAME" IS NULL AND "OVERLAPPING_CHANGES" IS NULL))
  26 - access("BILL_SEQUENCE_ID"="BBOM"."BILL_SEQUENCE_ID")
  28 - access("MSI"."INVENTORY_ITEM_ID"=NVL("COMPONENT_ITEM_ID","OEL"."INVENTORY_ITEM_ID") AND "MSI"."ORGANIZATION_ID"=92)
  30 - access("BSO"."OPERATION_CODE"="MSI"."SEGMENT1" AND "BSO"."ORGANIZATION_ID"="MP"."ORGANIZATION_ID")
  32 - access("BSOR"."STANDARD_OPERATION_ID"="BSO"."STANDARD_OPERATION_ID")
  33 - filter(("BR"."RESOURCE_CODE"='Labor' OR "BR"."RESOURCE_CODE"='Std Labor'))
  34 - access(ROWID=ROWID)
  35 - filter(("BR"."RESOURCE_CODE"='Labor' OR "BR"."RESOURCE_CODE"='Std Labor'))


I am curious about lines 10 and 11...

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                       | Name                         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
...
|  10 |           TABLE ACCESS BY INDEX ROWID           | VERP_OTM_STAGED_VONS         |      1 |      1 |      1 |00:00:00.01 |     228 |      0 |       |       |          |
|* 11 |            INDEX UNIQUE SCAN                    | VERP_OTM_STAGED_VONS_U2      |      1 |      1 |      1 |00:00:00.01 |       2 |      0 |       |       |          |
....


As I read this, it is accessing a single row (INDEX UNIQUE SCAN) from VERP_OTM_STAGED_VONS_U2 and getting the (by definition) single row for that from VERP_OTM_STAGED_VONS.

How could that be requiring 228 buffer gets?

I ran this DBMS_XPLAN while the VERP_OTM_STAGED_VONS table was being updated heavily and have a vague theory that most of the 228 buffers are actually spent reading UNDO to construct the last-committed version of the row. Is that reasonable?

If so, could that sort of mechanism be affecting the performance of the program doing the heavy updates?

Specifically, I am wondering if something like this could happen:

1) Program starts a loop...
a) UPDATE TABLE x....
b) (no commits or anything)
c) SELECT FROM TABLE x....

If that loop updated block "B", say, in table X 100 times, what would each read have to do to get the current version of that block? Would all the uncommitted updates be creating more work for it in terms of creating more UNDO to sift through?

Thanks in advance!

Matt

and Connor said...

Certainly operations along the lines of:

for i in ( select ... from my_table )
loop
   update my_table  -- ie, the same table as in the cursor
end loop;


can get into difficulty. Because its not about getting the *current* row, its about getting an *old* row. Because the logic of the code above (assuming it takes 1 second to update each row) is:

- its 9:00:00am, open a cursor on my_table
- fetch a row
- now update that row, its now stamped as being current as of 9:00:01am
- loop around
- fetch next row
- Oh! This *block* is marked as being at 9:00:01am (ie, the previous row update)
- Undo the change to get the block back to 9:00:00am
- Now the next row can be fetched
- now update that row, its now stamped as being current as of 9:00:02am
- loop around
- fetch next row
- Oh! This *block* is marked as being at 9:00:02am (ie, the previous row update)
- Undo the change to get the block back to 9:00:00am (two lots of undo)
- Now the next row can be fetched

etc etc etc

Here's a simple example

SQL> create table t ( x int, y int );

Table created.

SQL> insert into t values (1,1);

1 row created.

SQL> commit;

Commit complete.

SQL> exec dbms_stats.gather_table_stats('','T');

PL/SQL procedure successfully completed.

--
-- open a cursor at this point in time
--
SQL> variable rc refcursor
SQL> exec open :rc for select * from t;

PL/SQL procedure successfully completed.

--
-- now 1000 transactions on that table
--
SQL>
SQL> begin
  2  for i in 1 .. 1000 loop
  3    update t set y = y + 1;
  4    commit;
  5  end loop;
  6  end;
  7  /

PL/SQL procedure successfully completed.

--
-- here are my session stats BEFORE i fetch from that cursor
--
SQL> select
  2  s.name, st.value
  3  from v$statname s, v$mystat st
  4  where st.statistic# = s.statistic#
  5  and s.name in (
  6  'session logical reads',
  7  'consistent gets',
  8  'data blocks consistent reads - undo records applied');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
session logical reads                                                 10088
consistent gets                                                        7061
data blocks consistent reads - undo records applied                       0

3 rows selected.

SQL> print rc

         X          Y
---------- ----------
         1          1

1 row selected.

--
-- here are my session stats AFTER i fetch from that cursor
--

SQL> select
  2  s.name, st.value
  3  from v$statname s, v$mystat st
  4  where st.statistic# = s.statistic#
  5  and s.name in (
  6  'session logical reads',
  7  'consistent gets',
  8  'data blocks consistent reads - undo records applied');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
session logical reads                                                 11090
consistent gets                                                        8063
data blocks consistent reads - undo records applied                     995

3 rows selected.


So to fetch one row, I did 11090 - 10088 = 1002 logical reads, and 995 undo operations.

There are other *potential* causes (delayed block cleanout etc).

Rating

  (3 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

But the query I ran was in another session

Matthew McPeak, August 31, 2016 - 1:14 pm UTC

I was aware of the issues with looping on table X and updating table X in the cursor, but I appreciate your clear example of it. That will be a good reference.

However, the query for which I gave you the DBMS_XPLAN output was run from another session. I.e.,

Session 1: lots of updates on table X (no commits)
Session 2: query table X <-- that's the DBMS_XPLAN output. Why so many buffers to read by a single ROWID?

If session 2 runs the same query after session 1 is finished, the step to read the table by INDEX ROWID does not take more than 2 buffers, as one would expect.


Connor McDonald
September 01, 2016 - 2:50 am UTC

It is in effect the same scenario:

Session 1:
- do lots of updates (no commit). We *do* this work on the data blocks. We dont *wait* for the commit, and then apply the changes. (This is why a commit is "fast"). We go ahead and *make* those changes, assuming that its most likely you *will* commit at some stage.

Session 2 (running BEFORE the commit):
- read the block. It need to see the data *without* session 1 changes.
- So we need to apply all that undo.

Session 2: (running AFTER the commit):
- read the block and I want to *include* the committed changed. No problems, the block already reflects that.


... sorry, but why 228 of them?

Matthew McPeak, September 03, 2016 - 1:10 pm UTC

Thank you, that makes sense. But why 228 buffer gets?

Does Oracle make a new "version" every time session #1 updates a block even without committing?

I understand the need for a last-committed version (for session #2 to read) and a current version (for session #1 to update). Why 227 other versions (give or take)?
Connor McDonald
September 05, 2016 - 4:22 pm UTC

Oracle needs to work backwards through the undo until it hits the version of the block you need. So presumably there were a lot of updates to the row!

Also you need to subtract off the gets from the steps underneath the current one. So:

|  10 |           TABLE ACCESS BY INDEX ROWID           | VERP_OTM_STAGED_VONS         |      1 |      1 |      1 |00:00:00.01 |     228 |      0 |       |* 11 |            INDEX UNIQUE SCAN                    | VERP_OTM_STAGED_VONS_U2      |      1 |      1 |      1 |00:00:00.01 |       2 |


Is 2 gets for the index plus another 226 to access the table itself.

Chris

Légal notice

Ahonde Akouvi, September 05, 2016 - 8:03 pm UTC


more

Connor and Chris don't just spend all day on AskTOM. You can also catch regular content via Connor's blog and Chris's blog. Or if video is more your thing, check out Connor's latest video and Chris's latest video from their Youtube channels. And of course, keep up to date with AskTOM via the official twitter account.

More to Explore

PL/SQL demos

Check out more PL/SQL tutorials on our LiveSQL tool.

PL/SQL docs

PL/SQL reference manual from the Oracle documentation library