Wednesday, 30 March 2016

Full Table Scan not always as low as 0.5% of data!

Based on a reply from Jonathan Lewis to an OTN post on Explain Plans I need to correct some of the claims made in my previous post on Full Table Scans.

I'm going to repeat the inaccurate paragraphs and the Conclusions I posted then [edited here for brevity], and then point out the mistakes in them, and an attempt at a corrected set of paragraphs. I will also edit the original post and replace these incorrect paragraphs with the corrected ones.

I'll highlight the parts that are not strictly correct.
The main determinant for whether a FTS is the best access method is the fraction or percentage of the rows in the table being retrieved by the query, which are of course determined by the filter conditions in the query. If this fraction / percentage of data from the table is high enough then a Full Table Scan will always be a lower cost than using an Index Scan (except maybe for an Index Fast Full Scan, which is really another variation on a Full Scan).

So when you see a Full Table Scan in an execution plan you should check the query itself for how many rows it needs from the total number of rows in the table i.e. what percentage or fraction. If this is high enough then a FTS is indeed the "best" access method to get that data because it has the lowest cost. In which case you should really be asking why the query needs such a high percentage of the data from one table. Don't assume that the Optimizer is wrong - normally it isn't. It is just as likely to be your query that is affecting the execution plan chosen.

Conclusions

Although a Full Table Scan can seem a "brute force" approach to finding some matching records in a table, it can sometimes be the better way of doing it though. It all depends on how many rows you want back from the table as a percentage of the rows in the table.

If your query is retrieving more than about 0.20% to 0.35% of the data in a table then a Full Table Scan may well be the cheapest and best access method. [...]. Trying to force the Optimizer into using another access method in this circumstance is a waste of time, because all other access methods will be more expensive. The only exception might be another Full Scan type access, such as an Index Full Scan. But even then the gains (reduction in cost) will only be marginal i.e. not a full order of magnitude less.

When you see a FTS in a query execution plan you should check the estimated row count and what this is as a percentage of the row count in the table, and confirm if this estimate is correct or not. If the estimate is correct then a FTS is the lowest cost access method and the Optimizer is right to choose it. You should also check if your query is correct, or if there is something wrong with the filter conditions in it.
The main error is that it is wrong for me to claim any kind of actual figures for the percentage when the cutover will occur. As Jonathan points out in his reply on OTN it is possible for an index access to have a lower cost than a FTS for 24.5% of the data in a table, which is far above the 0.35% figure I mention. The actual cutover percentage is dependent on so many variables that it is incorrect for me to try and state a specific range for the cutover.

While I was not necessarily wrong in my specific examples because I made clear what my assumptions were, I was also not right in all possible scenarios. So I'm withdrawing my original Conclusions and updating them to be more strictly correct.
[paragraph deleted]

So when you see a Full Table Scan in an execution plan you should check the query and all other relevant factors to see if a FTS is indeed the "best" access method to get that data because it has the lowest cost. [deleted sentence] Don't assume that the Optimizer is wrong - normally it isn't. It is just as likely to be your query that is affecting the execution plan chosen.

Conclusions

Although a Full Table Scan can seem a "brute force" approach to finding some matching records in a table, it can sometimes be the better way of doing it though. It depends on several factors including how many rows you want back from the table, the number of blocks for the table, and the Clustering Factor of any indexes.

It is possible that for even low percentages of data being retrieved from a table that a Full Table Scan can be the cheapest and best access method. [...]. Trying to force the Optimizer into using another access method in this circumstance is a waste of time, because all other access methods will be more expensive. The only exception might be another Full Scan type access, such as an Index Full Scan. But even then the gains (reduction in cost) will only be marginal i.e. not a full order of magnitude less.

When you see a FTS in a query execution plan you should check many things including, but not limited to, the number of rows in the table, the number of blocks used for the table, the Clustering Factor for each possible index, and the estimated row count for the filters being used.

If the estimate is correct then a FTS is the lowest cost access method and the Optimizer is right to choose it. You should also check if your query is correct, or if there is something wrong with the filter conditions in it.

Counter Example

It is relatively simple to show a similar query to the ones I was using that uses an index instead of a full table scan for a far higher percentage of data in the table than 0.5%. Jonathan posted one such counter example in one of his replies on OTN, and we can easily replicate this using the same test data set from my original post.

select sum (one) from scantest where pkid between 1000000 and 2000000 ;

  SUM(ONE)
----------
   1000001

Statistics
----------------------------------------------------------
      10468  consistent gets
      10311  physical reads
   2  SQL*Net roundtrips to/from client
   6  sorts (memory)
   0  sorts (disk)
   1  rows processed

select sum (one) from scantest where pkid between 1000000 and 2000000

Plan hash value: 40453105

-----------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |              |       |       | 10282 (100)|          |
|   1 |  SORT AGGREGATE                      |              |     1 |     9 |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID BATCHED| SCANTEST     |  1000K|  8789K| 10282   (1)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN                  | IX_SCAN_PKID |  1000K|       |  2223   (1)| 00:00:01 |
-----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("PKID">=1000000 AND "PKID"<=2000000)
Note:
  • This query is retrieving 10% of the data in the table
  • An index range scan is being used to retrieve the data
  • A Full Table Scan had a cost of just over 22,000, so this index scan is much cheaper at 10,282
  • The key difference is the Clustering Factor of the pkid column
This index range scan is still cheaper when retrieving 20% of the data in the table:

select sum (one) from scantest where pkid between 1000000 and 3000000 ;

  SUM(ONE)
----------
   2000001

Statistics
----------------------------------------------------------
      20762  consistent gets
      20697  physical reads
   2  SQL*Net roundtrips to/from client
   6  sorts (memory)
   0  sorts (disk)
   1  rows processed

select sum (one) from scantest where pkid between 1000000 and 3000000

Plan hash value: 40453105

-----------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |              |       |       | 20562 (100)|          |
|   1 |  SORT AGGREGATE                      |              |     1 |     9 |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID BATCHED| SCANTEST     |  2000K|    17M| 20562   (1)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN                  | IX_SCAN_PKID |  2000K|       |  4442   (1)| 00:00:01 |
-----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("PKID">=1000000 AND "PKID"<=3000000)

Conclusion?

Be careful of generalising and summarising certain observed behaviours too much with Oracle. When considering index usage there is much more to it than just the number of rows being retrieved as a percentage of those in the table.

Monday, 21 March 2016

Creeping Slow Performance

A recent OTN post requesting help for a slow performing update where Oracle was doing a full table scan, also revealed that the update was getting slower and slower each month, and that new data was loaded into the table each month to be "processed" i.e. updated. Unfortunately this kind of design suffers from a natural creeping slowdown in the elapsed time of the update process. Each month it will take longer and longer to complete the processing of the newly loaded data, until any elapsed time targets are exceeded and it continues to take longer and longer to complete. There is a bad design pattern here, but obviously the original designers and implementers did not spot it.

Consider the following - in the first month after go-live the table only contains newly loaded data, so a full table scan is used. Let's say it takes 2 minutes to complete, and our target is 30 minutes for the whole process to complete, which includes other steps as well. Everything looks good performance wise, so we leave everything as it is and carry on.

The next month - month 2 - the size of the table has doubled, and Oracle still uses a full table scan because you want to update half the data in the table. This now takes 4 minutes because the table has doubled in size. But the overall process still completes within 30 minutes, so everything still looks good.

Over the next few months the table grows each month, and the elapsed time of the update continues to increase by 2 minutes each month, assuming a similar volume of data is loaded in each month. After 5 months the update now takes 10 minutes, but this is still within our 30 minute target.

But after 10 months the elapsed time is now 20 minutes, which is a significant proportion of the 30 minutes, and people are starting to ask questions. And after 15 months, if not sooner, the 30 minute target has been missed and the overall data load and process is now taking too long. Not only that, it is continuing to take longer and longer to complete each month, and will only get worse.

What can be done? Could an index help? No, is the simple answer. As I recently blogged in Full Table Scan - Friend or Foe?, the cutover point for the Optimizer to choose to use an index is when you want to retrieve less than 0.5% or so of the data in a table. After 10 months you are still processing 10% of the data in the table each month. And worse, even after 100 months (8+ years) you are still processing 1% of the data in the table each month, and a full table scan is still a lower execution cost than using any index on the table.

What could you do about this? One obvious solution is to use a "staging table" of the same structure into which the data is initially loaded each month. Then do the update and other processing on this table, and finally insert all the data into the main table. This solution does not suffer from the constant degradation in performance that the current one does. Oracle will still use a full table scan, but it is only reading from disk the data for this month, and so should complete in a relatively constant time each month - assuming data volumes are similar each month. The insert to the main table could be done quite quickly using the "append" hint for a direct load, and then the staging table could be truncated which should be very quick. Although the data is copied around in Oracle twice, it should still be much quicker than scanning a table with hundreds of months of data in it.

Other possibilities include partitioning by a key unique to each month's data, which is also used in the update statement so that partition pruning occurs. This may be problematic if there is not a clean partition key to use. It should not be a "processed flag", as this would be updated by the processing itself which would result in row movement between partitions and extra work by Oracle.

Ultimately the issue is about spotting these kind of bad design patterns early on and avoiding these pending future performance problems. To get to one month's data being less than 0.5% of the total data volume in the table would take you over 200 months, or almost 17 years. And during those 17 years this monthly data load processing would always take longer and longer to complete. A different design can avoid this future performance problem completely.

Tuesday, 1 March 2016

Full Table Scan - Friend or Foe?

[Or Don't be afraid of Full Table Scans]

UPDATE 30 March 2016
I've come to realise that there are some mistakes and inaccuracies in this post [see this post for more details], so I've edited this post and corrected what I can.  Rather than leave behind incorrect claims, I've replaced them by the corrected text, so hopefully now this post no longer has its previous faults.

ORIGINAL POST:
Many people consider a Full Table Scan (FTS) in a query execution plan to be a bad thing - reading every record from a table to find only those records the query needs. This is indicated by a "TABLE ACCESS FULL" in an execution plan. But is it really all that bad? Is it actually sometimes the right tool for the job? Can a Full Table Scan sometimes have a lower cost than using an Index?

My view is that the Oracle Optimizer will only choose a FTS under the following two conditions:
  • There is no other possible access method to get the needed data from the table
    • No other access method is currently available, but another access method might be a lower cost if it was available
  • A FTS is a lower cost (and so should be faster) than all other possible access methods
    • The FTS is the "best" access method of all available and the Optimizer is correct to use it
In other words, when you see a "TABLE ACCESS FULL" in an execution plan you should not jump to the conclusion that this is wrong and "needs to be fixed", because maybe it is correct and it is indeed the best access method for that particular step of the query operation. If you have concerns about the FTS then you need to double check things to find out whether it is the right thing for the Optimizer to be choosing, or whether a better access method would reduce the execution cost. Jumping to the wrong conclusion can lead you down a dead end when trying to improve a query's performance.

So when you see a Full Table Scan in an execution plan you should check the query and all other relevant factors to see if a FTS is indeed the "best" access method to get that data because it has the lowest cost.  Don't assume that the Optimizer is wrong - normally it isn't. It is just as likely to be your query that is affecting the execution plan chosen.

Calculating the Cutover Point

The actual percentage or fraction of rows in the table that is the cutover point between the Optimizer using a Full Table Scan or an available Index is itself mainly dependent on the average number of rows stored per data block. The other main factor is the value being used by the Optimizer for Multi-Block Read Count (MBRC), which is part of the System Statistics stored in the database. It is possible to calculate this cutover point yourself on a given table to see when a FTS really is cheaper and when an Index might help.

For a specific query involving an equality filter on a column, the other factor is what fraction of the data rows in the table have the same value stored in them. Oracle maintains this as a statistic on each column named "Density". By comparing the Density value for a column against the fraction of rows in the table needed by the query, you can see whether a FTS would be cheaper or not for a filter on that column. Remember that a percentage is just a fractional decimal value multiplied by 100 - so a Density of 0.0025 means 0.25%.

First the value used for MBRC (Multi-Block Read Count). This is stored in the AUX_STAT$ table owned by SYS. Its value only gets set when you gather system statistics. If set, then that particular value is used. If not set then a default value of 8 is used (note that it seems to ignore the value of the initialization parameter db_file_multiblock_read_count). The Optimizer also uses the values for MREADTIM and SREADTIM (Multi-block read time and Single block read time) also in the AUX_STAT$ table. Again, if these have not been set then it will use a default formula to derive them from the values for IOSEEKTIM and IOTFRSPEED.

To try and keep this explanation short we can jump to the following formulae used when you have not gathered system statistics.
SREADTIM = IOSEEKTIM + (DB_BLOCK_SIZE / IOTFRSPEED)  
MREADTIM = IOSEEKTIM + (MBRC * DB_BLOCK_SIZE / IOTFRSPEED) 
For the default values of MBRC (8), IOSEEKTIM (10) and IOTFRSPEED (4096) and a DB_BLOCK_SIZE of 8192 (8 KB) you get an SREADTIM value of 12 milliseconds, and a MREADTIM value of 26 milliseconds.

When a Full Table Scan occurs the Optimizer knows that it will be doing multi-block reads. However, it needs to cast or convert the cost of these reads into units of single block reads. This is because all other I/O costs are in terms of single block reads internal to the Optimizer. And the "cost" of a multi-block read is not the same as the "cost" of a single block read - a multi-block read should take longer given the greater number of blocks being transferred.

Instead of dividing the number of blocks in the table by the full MBRC value, it "adjusts" this value by the ratio of SREADTIM to MREADTIM, and then uses this value in the cost calculation.

The cost of a FTS would then be calculated as (note the brackets):
FTS Cost = #Blocks in Table / (MBRC * SREADTIM / MREADTIM)
FTS Cost = (#Blocks in Table * MREADTIM) / (MBRC * SREADTIM)
For an Index lookup to be cheaper than this FTS cost, we can calculate the fraction of rows in the table where the cost of using an Index would be slightly less than this FTS cost. For this we need to know the following values from the statistics Oracle has on the table and the particular column used in the equality filter:
  • Number of Rows in the table - NUM_ROWS in USER_TABLES or USER_TAB_STATISTICS
  • Number of Blocks used for the table - BLOCKS in USER_TABLES or USER_TAB_STATISTICS
  • Density of the column - DENSITY in USER_TAB_COLS or USER_TAB_COL_STATISTICS
A Full Table Scan is cheaper than using an Index lookup when:
Density > (BLOCKS * MREADTIM) / (MBRC * SREADTIM * NUM_ROWS)
When the Density of a column is less than this value then an Index lookup would be cheaper.

Conclusions

Although a Full Table Scan can seem a "brute force" approach to finding some matching records in a table, it can sometimes be the better way of doing it though. It depends on several factors including how many rows you want back from the table, the number of blocks for the table, and the Clustering Factor of any indexes.

It is possible that for even low percentages of data being retrieved from a table that a Full Table Scan can be the cheapest and best access method. Trying to force the Optimizer into using another access method in this circumstance is a waste of time, because all other access methods will be more expensive. The only exception might be another Full Scan type access, such as an Index Full Scan. But even then the gains (reduction in cost) will only be marginal i.e. not a full order of magnitude less.

When you see a FTS in a query execution plan you should check many things including, but not limited to, the number of rows in the table, the number of blocks used for the table, the Clustering Factor for each possible index, and the estimated row count for the filters being used. If the estimate is correct then a FTS is the lowest cost access method and the Optimizer is right to choose it. You should also check if your query is correct, or if there is something wrong with the filter conditions in it.

Tests

Lets show whether this holds true with some tests. There is quite a lot of output here, but I want to provide everything so that anyone else can reproduce these tests on their own systems.

Database version - 12.1.0.2.0
Operating System - Oracle Linux 7.2

Scan Test table - 10 million rows, with columns of different repeated values:
drop table scantest ;
--
prompt Loading data ....
create table scantest 
tablespace testdata 
as 
select r pkid
     , 1 one -- a constant, which forces actual data row access
     , mod (r, 10)     pct10   -- 10 values     = 10% of data in table
     , mod (r, 20)     pct5    -- 20 values     = 5% of data in table
     , mod (r, 50)     pct2    -- 50 values     = 2% of data in table
     , mod (r, 100)    pct1    -- 100 values    = 1% of data in table
     , mod (r, 200)    pct05   -- 200 values    = 0.5% of data in table
     , mod (r, 500)    pct02   -- 500 values    = 0.2% of data in table
     , mod (r, 1000)   pct01   -- 1,000 values  = 0.1% of data in table
     , mod (r, 2000)   pct005  -- 2,000 values  = 0.05% of data in table
     , mod (r, 5000)   pct002  -- 5,000 values  = 0.02% of data in table
     , mod (r, 10000)  pct001  -- 10,000 values = 0.01% of data in table
     , mod (r, 20000)  pct0005 -- 20,000 values = 0.005% of data in table
     , mod (r, 50000)  pct0002 -- 50,000 values = 0.002% of data in table
  from (select rownum r
          from (select rownum r from dual connect by level <= 1000) a,
               (select rownum r from dual connect by level <= 1000) b,
               (select rownum r from dual connect by level <= 1000) c
         where rownum <= 10000000) ;
--
prompt Gathering Statistics ....
exec dbms_stats.gather_table_stats ('JOHN', 'SCANTEST')
--
prompt Creating Indexes ....
create unique index ix_scan_pkid on scantest (pkid) ;
create index ix_scan_pct2 on scantest (pct2) ;
create index ix_scan_pct1 on scantest (pct1) ;
create index ix_scan_pct05 on scantest (pct05) ;
create index ix_scan_pct02 on scantest (pct02) ;
create index ix_scan_pct01 on scantest (pct01) ;
This produces a table with the following statistics:
                                TABLE STATISTICS

Table                           %F  IT           In Ext         Next Ext  %I
------------------------------ --- --- ---------------- ---------------- ---
SCANTEST                        10   1           65,536        1,048,576

                                     Avg Spc
    Num Rows       Blocks E Blocks  Free/Blk Chains Avg Row Len
------------ ------------ -------- --------- ------ -----------
  10,000,000       80,951        0       .00      0      53.000

Table                           Num Extents       Blocks   Avg Blocks
------------------------------ ------------ ------------ ------------
SCANTEST                               151        81,920          543

                                  Leaf         Distinct       Clustering
Index                  Height   Blocks             Keys           Factor
-------------------- -------- -------- ---------------- ----------------
IX_SCAN_PKID                3   22,132       10,000,000           80,528
IX_SCAN_PCT2                3   19,503               50        4,026,368
IX_SCAN_PCT1                3   19,518              100        8,052,718
IX_SCAN_PCT05               3   20,212              200       10,000,000
IX_SCAN_PCT02               3   20,629              500       10,000,000
IX_SCAN_PCT01               3   20,768            1,000       10,000,000

Full Table Scan cost is calculated as follows:
FTS Cost = (BLOCKS * MREADTIM) / (MBRC * SREADTIM)
On my system MREADTIM and SREADTIM are not set, and the others have default values in the system statistics in AUX_STAT$ (IOSEEKTIM = 10, IOTFRSPEED = 4096), so using the formula from before this gives SREADTIM of 12 ms and MREADTIM of 26 ms.

Plugging these values into the previous formula gives about 22,000 as the cost for the FTS:
(80951 * 26) / (8 * 12) = 2104726 / 96 = 21,924.23 
We can calculate the cutover point up to which a FTS would be cheaper than an Index Scan using the formula given before:
Density > (BLOCKS * MREADTIM) / (MBRC * SREADTIM * NUM_ROWS)
Density > (80,951 * 26) / (8 * 12 * 10,000,000) = 0.002192 or 0.22% approximately
Remember that this is based on several assumptions (Index Clustering Factor) and simplifications (ignoring CPU costs). Thus the cutover point will not be a precise value of 0.0022 (0.22%) but something around this value.

Having calculated the FTS cost at about 22,000 we can also calculate the expected Index Scan costs, and see whether they do drop below the FTS cost under 0.22% of the data in the table.

An Index Scan cost has 2 components:
Index Access Cost = Levels + (Leaf Blocks * Filter Factor)
 Data Access Cost = Clustering Factor * Filter Factor
The Filter Factor is the selectivity of a single value for an equality predicate filter, being the Density of the column, or one over the Number of Distinct Values. In real terms it is the percentage of rows being retrieved, which in our test table is indicated by the column name.

For all indexes the number of Levels is 3 and the number of Leaf Blocks is about 20,500. Yes, it does vary but it is not significantly different for the tests we are doing here. Also from index PCT05 onwards the Clustering Factor is always 10 million i.e. it is not clustered and it is the row count in the table.

Column Name% of Rows returnedFraction of RowsIndex CostData CostTotal Cost
pct11%0.013 + (20,500 * 0.01) = 3 + 205 = 2088,000,000 * 0.01 = 80,00080,208
pct050.5%0.0053 + (20,500 * 0.005) = 3 + 102.5 = 105.510M * 0.005 = 50,00050,106
pct020.2%0.0023 + (20,500 * 0.002) = 3 + 41 = 4410M * 0.002 = 20,00020,044
pct010.1%0.0013 + 20.5 = 23.510M * 0.001 = 10,00010,024

Our calculations confirm that the expected cost of an Index Scan should drop below that of a Full Table Scan when less than 0.22% of the data in the table is being selected.

Does this bear out in practise? Will Oracle switch from a Full Table Scan to an Index Scan when the fraction of rows requested drops below 0.0022? Lets see.

Note: The buffer cache and shared pool were flushed from a SYSDBA session before each query execution, so the buffer cache was empty in each case. And we are only interested in the I/O statistics from the query execution - other statistics such as Redo and SQL*Net bytes sent are not relevant and have been removed.

Query 1:
set autotrace on statistics 
--
select sum (one) from scantest where pct2 = 1 ;

  SUM(ONE)
----------
    200000

Statistics
----------------------------------------------------------
      80704  consistent gets
      80541  physical reads
          2  SQL*Net roundtrips to/from client
          6  sorts (memory)
          0  sorts (disk)
          1  rows processed
Execution Plan (from dbms_xplan.display_cursor for the SQL_ID):
select sum (one) from scantest where pct2 = 1

Plan hash value: 1745049784

-------------------------------------------------------------------------------
| Id  | Operation          | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |          |       |       | 22028 (100)|          |
|   1 |  SORT AGGREGATE    |          |     1 |     6 |            |          |
|*  2 |   TABLE ACCESS FULL| SCANTEST |   200K|  1171K| 22028   (1)| 00:00:01 |
-------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - filter("PCT2"=1)
Note:
  • 2% of 10 million rows is 200 thousand, which the Optimizer has correctly estimated.
  • Full table scan cost is 22,028. This is very close to my own estimate of about 22,000. The missing cost component would be for CPU work to filter each row.
  • 80,541 physical reads occurred, which is very close to the 80,951 blocks reported in the table.

Query 2:
Repeat this with a lower percentage column - pct05
select sum (one) from scantest where pct05 = 1 ;

  SUM(ONE)
----------
     50000

1 row selected.

Statistics
----------------------------------------------------------
      80704  consistent gets
      80541  physical reads
          2  SQL*Net roundtrips to/from client
          6  sorts (memory)
          0  sorts (disk)
          1  rows processed

select sum (one) from scantest where pct05 = 1

Plan hash value: 1745049784

-------------------------------------------------------------------------------
| Id  | Operation          | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |          |       |       | 22040 (100)|          |
|   1 |  SORT AGGREGATE    |          |     1 |     7 |            |          |
|*  2 |   TABLE ACCESS FULL| SCANTEST | 50000 |   341K| 22040   (1)| 00:00:01 |
-------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - filter("PCT05"=1)
Note:
  • Rows estimate is now 50,000, as expected
  • Full table scan cost is slightly different for some unknown reason, but still about 22,000.
  • Same number of physical reads occurred - 80,541.

Query 3:
Continue down to the next lower percentage column - pct02
select sum (one) from scantest where pct02 = 1 ;

  SUM(ONE)
----------
     20000

1 row selected.

Statistics
----------------------------------------------------------
  20212  consistent gets
  20060  physical reads
      2  SQL*Net roundtrips to/from client
      6  sorts (memory)
      0  sorts (disk)
      1  rows processed

select sum (one) from scantest where pct02 = 1

Plan hash value: 3458310886

------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |               |       |       | 20049 (100)|          |
|   1 |  SORT AGGREGATE                      |               |     1 |     7 |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID BATCHED| SCANTEST      | 20000 |   136K| 20049   (1)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN                  | IX_SCAN_PCT02 | 20000 |       |    44   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("PCT02"=1)
Note:
  • Now 0.2% of data in this table, which is low enough that an Index Scan should be cheaper
  • Index cost is indeed lower than a Full Table Scan, as expected - 20,049 versus 22,040
  • Index cost is very close to our own calculation of 20,044 - again CPU cost is the difference
  • Only 20,060 physical reads now - Index branch blocks + Leaf blocks + Data rows

Query 4:
Repeat this with a lower percentage column - pct01
select sum (one) from scantest where pct01 = 1 ;

  SUM(ONE)
----------
     10000

1 row selected.

Statistics
----------------------------------------------------------
      10192  consistent gets
      10038  physical reads
          2  SQL*Net roundtrips to/from client
          6  sorts (memory)
          0  sorts (disk)
          1  rows processed

select sum (one) from scantest where pct01 = 1

Plan hash value: 1707962624

------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |               |       |       | 10025 (100)|          |
|   1 |  SORT AGGREGATE                      |               |     1 |     7 |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID BATCHED| SCANTEST      | 10000 | 70000 | 10025   (1)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN                  | IX_SCAN_PCT01 | 10000 |       |    23   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("PCT01"=1)
Note:
  • Index cost is halved because row count is halved - 10,025 versus 10,024 calculated
  • Only 10,038 physical reads now - Index branch blocks + Leaf blocks + Data rows

Query 5:
If we force the use of an index for the query on the PCT05 column using a hint we get the following:
select /*+ index (scantest (pct05)) */ sum (one) from scantest where pct05 = 1 ;

  SUM(ONE)
----------
     50000

Statistics
----------------------------------------------------------
  50271  consistent gets
  50133  physical reads
      2  SQL*Net roundtrips to/from client
      6  sorts (memory)
      0  sorts (disk)
      1  rows processed

select /*+ index (scantest (pct05)) */ sum (one) from scantest where pct05 = 1

Plan hash value: 3145193111

------------------------------------------------------------------------------------------------------
| Id  | Operation                            | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                     |               |       |       | 50116 (100)|          |
|   1 |  SORT AGGREGATE                      |               |     1 |     7 |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID BATCHED| SCANTEST      | 50000 |   341K| 50116   (1)| 00:00:02 |
|*  3 |    INDEX RANGE SCAN                  | IX_SCAN_PCT05 | 50000 |       |   104   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("PCT05"=1)
Note how the estimated cost is 50,116, which is far greater than the 22,028 of a full table scan, and agrees with my earlier calculation of 50,106 for this index. Instead of the 80,000 physical disk reads done before, only 50,000 have been done. However, the 80,000 disk reads were really multi-block disk reads i.e. nearer 10,000 real disk reads would have been done, each for 8 disk blocks at once. The 50,000 disk reads for the index execution plan would be single block disk reads.

Monday, 25 January 2016

What's Going On? Oracle Activity Monitoring Views

How do you find out what is happening now inside an Oracle database instance when you only have SQL level access to the database instance, and no nice GUI management tool? I'll cover how to start doing this with some SQL query examples.

A user is complaining that the application is running slowly, or a report someone scheduled is taking too long to finish - where do you look to find out what is going on inside the Oracle database right now? Well if you have a nice GUI based tool such as Enterprise Manager then go there first, because that will have summary screens of what is going on, and also drill downs into the details behind what is going on. Such tools are easier and quicker to use, and mean you don't have to remember the names of internal Oracle dynamic performance views.

But what if you don't have a nice GUI based tool? Or you want to work out for yourself what is really going on in Oracle? Or something has happened to the nice GUI tool and you cannot use it for one reason or another? Then you need to know about Dynamic Performance Views in Oracle, also known as the V$ tables, and which ones are the most relevant ones. The Dynamic Performance Views are views defined internal to Oracle that in fact map onto memory structures inside the SGA (System Global Area). They enable you to see in real time various data within the SGA using normal SQL queries.

When investigating performance problems you should generally narrow it down to a specific problem and the users being affected by it. In Oracle each connected user has a corresponding "session" inside the Oracle database instance, and information on each session is made available in the V$SESSION dynamic performance view.

This is both an advantage and disadvantage of the Dynamic Performance Views - they are a snapshot of current values in the SGA, and these values can be changing all of the time. Look again and you will get different results. Some views show cumulative values rather than current values, but they are always increasing over time and also constantly changing.

But with that in mind, you can use the V$SESSION view to look at what specific sessions are doing at the moment, and look for any slow, long running SQL statements. We can group the data columns into the following related groups:
  • Session Connection Information - User name, Client Application software, Logon time
  • Current Activity Information - Status, SQL statement executing
  • Delays - both normal Waits and abnormal Blocks i.e. small delays or completely blocked
    • Waits are delays that will definitely finish e.g. read a block from disk
    • Blocks are delays that are outside the control of the session and can potentially go on forever
      • e.g. blocked waiting for a row lock held by another session
For a full list of the columns in V$SESSION look in the "Oracle Database Reference" Manual under "Dynamic Performance Views", where you will get a brief description of each column.

All Active Sessions

Want a list of all active sessions and whether they are waiting or not? Try this query from SQL*Plus:
-- List the active sessions and break down key data
--
column sid              format 999999
column db_user          format a8      heading 'USER'
column db_login_time    format a6      heading 'LOGON'
column program          format a10     heading 'APP_N'
column active_for       format     999 heading 'ACTV|FOR'
column state            format a5      heading 'STATE'
column waiting_for      format     999 heading 'WAIT|FOR'
column event            format a12     heading 'WAIT ON'
column sql_id           format a13     heading 'SQL ID'
--
select s.sid, 
       nvl (s.username, 'SYS') db_user, 
       to_char (s.logon_time, 'hh24:mi') db_login_time,
       substr (s.program, 1, 10) program,
       s.last_call_et active_for,
       decode (s.state, 
                'WAITING', 'WAIT',
                'WAITED KNOWN TIME', 'NW L',
                'NW S') state,
       decode (s.wait_time, 0, seconds_in_wait, 0) waiting_for,
       substr (s.event, 1, 12) event, 
       nvl (s.sql_id, 'Not Executing') sql_id
  FROM v$session s
 WHERE s.type = 'USER'
   AND s.status = 'ACTIVE'
   AND s.wait_class != 'Idle'
/
--
Note the following about this query:
  • It restricts the sessions to only those from real users (not internal background sessions) that are active and experiencing non-idle waits.
    • Idle waits are generally waits external to Oracle, such as waiting for the next SQL statement to execute
  • The number of columns of data output is kept low to fit within an 80 column wide terminal screen
    • If you have a wider output format then you could add extra data columns to the "select"
  • The "decode" of "state" is meant to encode the following combinations of possibilities:
    • WAIT = WAITING, NW = NOT WAITING; PREV WAIT:- S = SHORT, L = LONG
    • i.e. it combines both whether the session is currently waiting or not, with whether the previous wait was a short or long wait
  • It is assumed that users have all connected today, so only the time of connection is shown
    • If connections are long lived, then change the date format used in the "to_char" to include the day
From this you can see the following:
  • How many sessions are active, and how many are currently waiting on something?
    • Sessions that are active and not waiting are therefore running on a CPU
  • How many sessions are running the same SQL statement? Look at the values of SQL_ID
  • How many sessions are experiencing the same kind of wait event?
  • Are sessions experiencing long or short waits most of the time?
 

One Session's Details

If you know the SID (Session ID) of one session you are interested in and want to drill down further, then you could run the following set of queries from within SQL*Plus:
--
set newpage none
--
set define on
undefine SESSION_ID
--
accept SESSION_ID prompt 'Enter Session ID > '
--
column sid          FORMAT 99999
column username     FORMAT a12
column logt         FORMAT a12 HEADING 'Logon Time'
column sql_start    format a9  heading 'SQL Start'
column last_call_et            heading 'Time at Status'
column module       FORMAT a16 heading 'Module'
column client_info  format a16 heading 'Client Info'
column command      format 999 heading 'cmd'
column taddr        format a8  heading 'TX Addr'
column server                  heading 'Server|Type'
column schemaname   format a12 heading 'Schema|Name'
column type                    heading 'Session|Type'
column sql_id                  heading 'Curr SQL ID'
column prev_sql_id             heading 'Prev SQL ID'
column lockwait     format a8  heading 'Wait Lock|Addr'
column event        format a25 heading 'Waiting For'
column wait_class   format a12 heading 'Wait Class'
column row_wait_obj#           heading 'Object|Waiting On'
column wait_time               heading 'Last Wait Time|(0=Waiting)'
column seconds_in_wait         heading 'Elapsed From|Last Wait'
column blocking_session        heading 'Blocking|Session ID'
column blocking_session_status heading 'Blocking|Sess Status'
--
select sid, 
       username, 
       to_char (logon_time, 'dd/mm hh24:mi') logt, 
       status,
       last_call_et,
       to_char (sql_exec_start, 'HH24:MI:SS') sql_start
from v$session
where sid = &&SESSION_ID
/
--
select sid, 
       substr (module, 1, 24) module, 
       substr (client_info, 1, 30) client_info,
       server, schemaname, type
from v$session
where sid = &&SESSION_ID
/
--
select sid, 
       sql_id, prev_sql_id, 
       event,
       substr (wait_class, 1, 20) wait_class
from v$session
where sid = &&SESSION_ID
/
--
select sid, 
       lockwait, 
       row_wait_obj#,
       wait_time, seconds_in_wait,
       blocking_session, blocking_session_status
from v$session
where sid = &&SESSION_ID
/
--
column sql_text format a62
--
select sql_id, sql_text from v$sql
where sql_id = (select sql_id from v$session where sid = &&SESSION_ID)
/
--
undefine SESSION_ID
--
set newpage 1

This gives you a lot more information from V$SESSION for the one session, broken down into related sets of data, as described before. Note that the final query selects from V$SQL which is probably the other main Dynamic Performance View, which has an entry for each SQL statement currently in the library cache in the SGA. Remember that a SQL statement in the library cache can be shared between many sessions.

One Session Detailed Drill Down

If you really want to drill down more into what a single session or a set of sessions is doing over a period of time then you could use Tanel Poder's snapper.sql. This snapshots the contents of V$SESSION and other Dynamic Performance views over a period of time and reports on what it captured. Mainly this will be the wait events experienced by the sessions, but a lot of other activity statistics are reported too.

Snapper is written in PL/SQL and uses two in-memory PL/SQL tables for each snapshot, and then lists out anything that has changed between them. It does not write anything to the database, and only needs minimal permissions - SELECT_CATALOG_ROLE and execute on DBMS_LOCK.SLEEP. Thus it is safe to run on any database.

Conclusion

I've shown how to list all the currently active sessions on a database including the SQL they are executing and what they are waiting on, and how to get more details on what just one session is doing.

If you want even more information on what a single session is doing then you can SQL Trace it, which creates a trace file on the database server of all the SQL statements executed by that session and all the waits it experienced while tracing was enabled. Nothing is missed out because every executed SQL statement from that session is traced. You can then use utilities such as "tkprof" to post process the trace file and report on the SQL statements executed, their elapsed times, and the waits they experienced.

If the slow down is not currently happening but was very recent then you can look back at the recent past using ASH (Active Session History), but note that ASH is an extra cost option - you must have the Diagnostic Pack of the Enterprise Edition of Oracle. I'll write something about using ASH in a future post.

Tuesday, 29 December 2015

GRUB, os-prober and Red Hat / Oracle Linux

I've been successfully using VirtualBox to have test environments to run Oracle Linux and Oracle Database in from some time, but there are limitations to what you can do. So I decided that I wanted to install Oracle Linux onto another disk partition on my PC so I could dual boot into it for some more advanced Oracle Database tests. Well the Oracle Linux installation itself went ahead trouble free - I just had to remember to disable GRUB bootloader installation as GRUB was already installed from my other Linux (Arch Linux) - but then I ran into some problems trying to get this newly installed Linux added properly to the main GRUB boot menu I was using. This post describes why this occurred (after much digging around on my part), and a very quick and simple solution for it.

Detecting other Linux installations on other disk partitions to add to the GRUB boot menu is done on Arch Linux by installing the "os-prober" package which adds some extra scripts used by "grub-mkconfig". The specific problem is that while "os-prober" did detect the Oracle Linux kernels, they were being added to the GRUB menu in the wrong order - it looked like an alphabetical ordering rather than a numeric ordering by kernel version number. This meant that the first Oracle Linux kernel listed in the GRUB menu was not the latest one installed, and in fact more likely to be the oldest one instead or a rescue kernel.

To cut a long story short the problem is due to a combination of the code in the "/usr/lib/linux-boot-probes/mounted/40grub2" detection script and the contents of the "/boot/grub2/grub.cfg" file in the Oracle Linux installation. The "grub.cfg" file in the Oracle Linux installation uses some keywords that are not detected by the "40grub2" script in Arch Linux, so the bootable Linux kernels are not listed in the same order as they are in the source "grub.cfg" file. Instead it is the "90fallback" script that detects the bootable Linux kernels when it is run afterwards by "os-prober". Actually it is run by "linux-boot-prober" and it does a direct listing of Linux kernel files in the "/boot" directory of the other Linux disk partition, and adds each of these to the local GRUB configuration file. And the result of this is that the other Linux kernels are detected and added in alphabetical order.

Details on the Problem

The "40grub2" script works by opening the "/boot/grub2/grub.cfg" file from another Linux installation and looking for the entries for bootable Linux kernels. The idea is that "40grub2" will find Linux kernels in the same order they are in the "grub.cfg" on the other Linux installation, and they will be added to the local "grub.cfg" file in the same order. The benefit of this method is that the first Linux kernel listed for this other installation in the main GRUB boot menu will be the same one as listed by the other Linux installation itself. Which in turn means that if it sorts the Linux kernels in any way or puts a specific Linux kernel first as the default in its "grub.cfg" configuration file, then this is also reflected in the local GRUB configuration file of my main Linux installation.

The "40grub2" script works by opening the "/boot/grub2/grub.cfg" file of the other Linux installation and then reads each line in turn looking for ones that begin "menuentry", "linux" or "initrd". I believe that these are "standard" keywords that GRUB should be using. Unfortunately Oracle Linux is using keywords of "linux16" and "initrd16" instead, which means that these lines are not matched at all by the "40grub2" script and no bootable Linux kernels are matched at all. It seems that Red Hat on which Oracle Linux is based uses these keywords for some obscure, historical reason or other. Either way, they are used and they do not match what "40grub2" is looking for.

Instead the bootable Linux kernels are detected by the "90fallback" script when it runs afterwards, and they are detected in alphabetical naming order as mentioned before.

Solutions

There is a quick, easy and good enough solution you can do yourself, and then there is a more official solution.

First, you can just manually edit your local "40grub2" file and change two lines in it. Add a "16" variation to the lines in the "case" block that test for "linux" and "initrd". Here is the output from "diff" showing the before (<) and after (>) versions of the two lines I changed.

67c67
<    linux)
---
>    linux | linux16 )
80c80
<    initrd)
---
>    initrd | initrd16 )
Once edited run "grub-mkconfig" again to regenerate your "grub.cfg" file, and it should correctly pick up those entries from the other Linux installation now.

Second, it does not look like there is actually an official solution, which can often be the case with open source software. I found some bug reports about this problem but there was some finger pointing going on both ways between the GRUB people and the Red Hat people. It looked like the GRUB people felt that the official keywords were "linux" and "initrd", so it was a Red Hat problem to solve; while the Red Hat people felt that "linux16" and "initrd16" were valid in a GRUB configuration file and did work so it was a GRUB problem with the "40grub2" script.

One person did raise the question on how the main Linux that is adding these entries to its local "grub.cfg" file should be treating these entries with the "16" suffix from the other Linux. Should it ignore them and just use the normal keywords in its own "grub.cfg" file, or should it use exactly the same keywords? The latter solution is a problem because the keywords found in the other "grub.cfg" file are NOT returned back to the "os-prober" script i.e. it is assumed they are only "linux" and "initrd". Making "40grub2" return these extra keywords as extra data fields would need a lot of changes in other places - both "40grub2" and "os-prober" at least, and possibly others too if there is a common format used for passing around information on bootable Linux kernels.

So you can see how something that looks simple can grow into something much bigger, and could have significant changes to something as important as GRUB. And GRUB is a very critical piece of software used at system boot time, so no "obvious solution" should be rushed through without a lot of extra thought and testing. Unfortunately I don't know when we will get any kind of "official solution" to this.

Monday, 28 December 2015

Oracle In Memory and CPU Execution Efficiency

Tanel Poder has been doing a series of posts on "RAM is the new disk" trying to show how the new "Oracle Database In-Memory" feature in Oracle 12c uses memory in a different and more efficient way than the normal, traditional buffer cache does. He hasn't finished the series of posts yet, but I started to draw some of my own conclusions from the data he published in his last post and I'd thought I'd publish my thoughts.

I know a reasonable amount about how CPU's work internally, so I assumed that the main performance improvement of Oracle Database In-Memory would be from a better memory access pattern that would significantly reduce the number of execution stalls inside the CPU. Tanel is one of the good Oracle bloggers, and he has been sharing the details of the tests he has been doing in this series of blog posts as well as the results from them so I can see if my hypothesis on the new Database In-Memory holds up.

Tanels' Tests

The main results are in this post where he gives the 6 SQL queries he ran and their results in terms of elapsed time and CPU execution cycles - some against the traditional buffer cache and some against the new In-Memory cache. No disk accesses were involved as all the data was already in memory in the Oracle SGA.

I'm only interested in the main 2 SQL queries that are the same as each other, except the first one gets its data from the traditional data block based buffer cache in memory while the second gets its data from the new In Memory column storage based cache i.e. both execute the same "SELECT" against the same table and all of the data needed is already in memory in the SGA.
3. FULL TABLE SCAN BUFFER CACHE (NO INMEMORY)
SELECT /*+ MONITOR FULL(c) NO_INMEMORY */ COUNT(cust_valid)  
FROM customers_nopart c WHERE cust_id > 0;

4. FULL TABLE SCAN IN MEMORY WITH WHERE cust_id > 0
SELECT /*+ MONITOR FULL(c) INMEMORY */ COUNT(cust_valid) 
FROM customers_nopart c WHERE cust_id > 0;

Tanel has also made all the low level CPU execution measurements available in a Google online spreadsheet. Here is a cut and paste of the CPU measurements for just the 2 queries I am interested in:

MetricTABLE BUFCACHETABLE INMEMORY PRED
task-clock-ms273741578
cycles864286530404573793724
instructions321154128777080326242
branches7386220210940579984
branch-misses220563974637243
stalled-cycles-frontend766970494202251325295
stalled-cycles-backend586273933951328333827
cache-references25644038411507915
cache-misses2220369817316366
LLC-loads2343611899712269
LLC-load-misses2185702947272805
LLC-stores184935821697666
LLC-store-misses323323127797
L1-dcache-loads73249460421069917316
L1-dcache-load-misses30527634185368159
L1-dcache-prefetches3689030225169253

The most obvious observation is that the In-Memory query execution is 17.34 times faster than the traditional buffer cache query execution (elapsed task-clock-ms time ratio of 27374 / 1578). I'm most interested in trying to explain what has caused this difference in elapsed time.

My Hypothesis & CPU / Memory Access

At the beginning of this post I stated that I assumed that the main performance improvement would be a result of a reduction in the number of execution stalls inside the CPU. Let me try and explain what I mean by that.

In the very old days of Intel CPU's (from the original 8086 up to the first '486 I think) the internal clock of the CPU (the rate at which it executed instructions) was the same as the external clock of the system which also governed memory access times. A read from the CPU of a memory location would take something like 3 or 4 external clock cycles (put the address on the system bus, the memory to process that to its output, put the data out on the bus to the CPU). During these clock cycles the CPU cannot proceed with the execution of that instruction i.e. it stalls until the data it needs from memory has been read into the CPU.

During the '486 lifetime Intel introduced technology that allowed the internal clock of the CPU to run faster than the external clock i.e. at a multiple of the external system clock. Now we have external clocks of 100 MHz typically and CPU internal clocks of 3 GHz and more i.e. the CPU is running internally at 30 or more times the external system clock rate.

A side effect of this change is that now when a CPU "stalls" to read needed data from memory, the stall is for much longer in terms of CPU instruction cycles. As the external clock is now 30 or more times slower than the internal clock of the CPU, the CPU may end up waiting doing nothing for over 100 execution cycles. NB. This is a simplification of what really happens, but it does describe a real effect.

We can see this effect in the separately reported statistics for "CPU cycles" and "CPU instructions completed" - the first one will be much higher than the second one. The "efficiency" of how a CPU executed a given piece of program code can be seen from the calculated "instructions per cycle" value i.e. "CPU instructions completed" divided by "CPU cycles". The closer this value is to 1 the more efficient the execution has been within the CPU. The lower this value is then the more "stalls" occurred within the CPU during execution that stopped it completing execution of an instruction every clock cycle.

Of course CPU designers have tried to work around or reduce the effect of such stalls in various ways, the details of which are not relevant here. It just means that a) there is various technology in the CPU to try and minimise the occurrence and impact of such "memory load stalls", and b) the net impact of such "memory load stalls" is much less than the 100 or so wasted execution cycles I've described. In fact, and this is also important, modern CPU's can actually issue more than one instruction at the same time for execution within the same clock cycle e.g. an integer operation and a floating point operation. This can result in an "instructions completed per clock cycle" value larger than 1, which can occur when executing well optimised program code.

If my hypothesis is correct then we should see a difference in the number of "stalls" in the CPU execution statistics between the 2 SQL query executions, and the ratio between these 2 sets of "stall" statistics should be close to the observed ratio in execution times.

My Initial Conclusions

To cut to the chase a bit, the observed difference in execution times between the 2 SQL queries is not wholly explained by just a reduction in the number of "stalls" inside the CPU, but the reduction in "stalls" is a significant contributor to this reduction in elapsed time. The reduction in elapsed time is roughly a 50:50 split between a reduction in the total number of instructions executed (code efficiency) and CPU memory access stalls (memory access efficiency).

We can see from the measurements that Tanel has reported that the number of instructions executed by the CPU decreased by a factor of 4.54 (32115412877 / 7080326242) to process the same amount of data (rows in the table). This is a significant improvement in code efficiency to process this volume of data - probably a result of the In-Memory cache using far simpler internal data structures than the traditional buffer cache that can in turn be processed much easier.

This leaves an improvement factor of 3.82 (17.34 / 4.54) that needs to be explained by something else. I propose that this other factor is due to a reduction in the number of "stalls" within the CPU when executing these instructions as described earlier. This will have the net effect of increasing the "instructions per cycle" value during the execution of the SQL query, and indeed we can see this from the measurements reported by Tanel:
  • Buffer cache SQL query execution has CPU instructions per cycle of 32115412877 / 86428653040 = 0.37
  • In-Memory cache SQL query execution has CPU instructions per cycle of 7080326242 / 4573793724 = 1.55
  • This gives an improvement ratio of 1.55 / 0.37 = 4.17
And this value is very close to the 3.82 value for the other performance improvement factor.

Trying to drill down further into this difference in "instructions per cycle" and identifying "CPU memory stalls" due to data access is difficult if not impossible for a number of reasons:
  • Above the L1 cache on the CPU the other CPU caches are shared by both instructions and data. We cannot tell which cache reads and which cache misses were due to fetching an instruction to execute or fetching a piece of data needed by an instruction being executed. Both lead to CPU stalls but for different reasons.
  • The In-Memory cache SQL query is executing a completely different code path within Oracle with almost 78% fewer instructions being executed in total (100 / 4.54). So we cannot assume that the instruction execution profile and also instruction cache misses are similar in both cases.
We can however see other evidence that this other factor for the improvement in performance is due to a reduction in CPU stalls. Tanel has reported two other CPU execution statistics - "stalled-cycles-frontend" and "stalled-cycles-backend". Tanel gives descriptions for these in his part 2 post, which I will summarise as follows:
  • Stalled cycles front end occurs before an instruction gets executed by the CPU and is generally due to fetching an instruction from memory
  • Stalled cycles back end occurs during instruction execution and is generally due to fetching data from memory needed by that instruction
So the most relevant statistic for stalls due to reading data from memory is "stalled-cycles-backend". We cannot compare these directly between the two SQL query executions because they executed a different number of instructions (remember the 4.54 reduction factor). What we can do is normalise these to a "stalled cycle per cycle" value and then compare them:
  • Buffer cache SQL query execution has backend stalls per cycle of 58627393395 / 86428653040 = 0.68
  • In-Memory cache SQL query execution has backend stalls per cycle of 1328333827 / 4573793724 = 0.29
  • This gives an improvement ratio of 0.68 / 0.29 = 2.34
Again, this is a significant improvement and shows that the number of stalls due to memory accesses by the CPU for data has been reduced.

Why Have Stalls Reduced?

I hope that I have shown that part of the improvement in the performance of the In-Memory cache has been the reduction in the number of "memory access stalls" in the CPU when executing the SQL query i.e. less time wasted waiting to read data in from main memory with a corresponding increase in the number of instructions executed per clock cycle and less total elapsed to execute those instructions. But how has Oracle actually managed to achieve this? How has it managed to reduce the number of "memory access stalls" while executing the same SQL query i.e. if it needs to read the same "set of data" to perform the same SQL query, how has it managed to read it more efficiently?

I am guessing that this is due to two specific factors:
  1. Data layout in memory - the layout is more "compact" which decreases the total amount of memory that must be read
  2. Sequential access to that memory, causing the CPU to "prefetch" the next memory line into the CPU cache, so it is already there when it is needed i.e. overlapping the processing of one memory line with the fetching of the next memory line
Note that this is based on what I have read on In-Memory as I've not yet had a chance to do any real testing of it yet. Again, thanks to Tanel for both doing some real testing and for sharing all the results he got from those tests.

In the traditional buffer cache a data block will span multiple memory lines (assuming a 64 byte memory cache line, as Tanel states) and this will contain data for all the columns in a row. When you only need the data from one column it means that you are skipping about in memory quite a lot, jumping from row to row, and not using most of the data in each block or memory line. In the new In-Memory cache the data is stored by column, so all the data for one column is stored together, next to each other in memory. This immediately reduces the total amount of memory that must be read to access the data for one column across all the rows in the table.

It also will increase the cache efficiency within the CPU, because one memory line in the cache will contain data for multiple rows i.e. the CPU can process the data for that column from multiple rows before it needs to read in another memory line into cache to get the next set of rows' data.

If the data for a column is physically laid out sequentially and contiguously in the system's memory, then it means that Oracle will be doing a series of sequential memory reads to process all the data for one column. Modern CPU's can detect this kind of sequential memory access and have an optimisation to "prefetch" the next data line from memory while the previous data line is still being processed. The net result is that stalls are either eliminated because the next line of data is already in the CPU cache or the impact of stalls is significantly reduced because the data is already on its way from memory to the CPU cache.

We can see evidence for this occurring in the "L1-dcache-prefetches" CPU statistic. The "L1 data cache" is the first on chip cache immediately used by the CPU core, and is small but very fast. All data needed by the CPU goes through this cache. Again, normalising to a "prefetch per instruction executed" we can see that the number of data prefetches by the CPU increased significantly during the In-Memory cache SQL query execution:
  • Buffer cache SQL query execution has L1 dcache prefetch per instruction executed of 36890302 / 32115412877 = 0.00115
  • In-Memory cache SQL query execution has L1 dcache prefetch per instruction executed of 25169253 / 7080326242 = 0.00355
  • This gives an improvement ratio of 0.00355 / 0.00115 = 3.09

The End

Well that's been a longer post than I wanted, but I wanted to get everything together into one post as I'm sure Tanel will finish his series of posts soon and probably make similar observations. And I wanted to see if he would come to exactly the same conclusions or slightly different ones, and doing this post was the only way to do that. Thanks again to Tanel for doing the tests and sharing all the data with us.

Monday, 14 December 2015

Python for the DBA (2) - Data Unloading

I've mentioned before that I like the Python programming language. Not only is it a "clean" language for writing programs in with a rich set of data types and structures for manipulating data, it also has a standard API for database access making it "database neutral". This makes it relatively easy to get data that is in a database into and out of your Python code where you can use the power of Python for whatever kind of data manipulation you need.

To show how easy it is to get data into a Python program I'll show a little utility to unload data from one table in a database to a flat, text file as one record per line with each data field separated by special delimiters.

Assuming the following:
  • Your Python program already has a database connection
    • This is relatively easy, but does vary by specific database driver being used
  • And it has opened the output file to unload to i.e. an open file handle and not the file name
  • And it has the name of the table, the field delimiter characters and the record terminator characters in local variables
Then you can write a simple function to call that will unload the data from that table to the specified file:
def unload_table_to_file (db_conn, table_name, out_data_file, field_separator, record_terminator) :
    # Preparation steps before doing the real work
    # Replace literals of special characters in the separator and terminator
    record_terminator = record_terminator.replace ('\\n', '\n')
    field_separator = field_separator.replace ('\\t', '\t')
    
    # Simplest SQL to get the data, assume column ordering is correct
    select_SQL = "select * from " + table_name
    
    # Now do the work - read in all records and output them
    print ("=== Unloading . . .")
    select_cursor = db_conn.cursor ()
    select_cursor.execute (select_SQL)
    for data_row in select_cursor.fetchall () :
        # Convert Python native data types to simple string representations
        output_fields = []
        for data_field in data_row :
            output_fields.append (str(data_field))
        out_data_file.write (field_separator.join (output_fields) + record_terminator)
    print ("=== Finished")
The main lines are:
  • First make sure that if any "escaped characters" are in the delimiters then they are the real escape characters
    • "\t" means the TAB character, and "\n" means the NEWLINE character
  • We just use a "select * from table" to get all the data into the Python code
    • The String concatenate operator is just the "+" operator i.e. "+" is overloaded depending on data type
  • And we execute this "select" via a Cursor created from the database connection passed in
  • The real work happens in 2 nested loops - for each data row, for each data field in each data row
    • The fields from one record are put into a list (essentially equivalent to an array)
    • This is so we can use a single action at the end to concatenate them all together with each data field value separated by the "field separator"
    • Then we "write" out this concatenated list of fields to the output file
  • The "str" function will return the String representation of a data value e.g. convert an integer to its String representation
    • This assumes that there exists a data type specific "str" method for each possible data type
  • The "join" method of a String variable iterates over a list of data, and returns one String of the list contents concatenated together with the value of the String variable between each one.
I think this shows some of the power and elegance of Python that reading all the data from a table can be done with so few lines of code, and that the code itself is so readable. And this code is flexible enough to deal with different values for the field separator characters and the record terminator characters. You could just do a classic comma separated list (',' as the field separator) or something more complicated to avoid issues where a comma may appear in the data itself e.g. "|__|" as the field separator (vertical bar, underscore, underscore, vertical bar). And this flexibility is all handled by this Python code.

Caveats

This is probably the most simple Python code to achieve the goal of reading all the data in a table and writing out to a flat, text file. There are several things it does not do at all, and other things that could be enhanced with it.
  • It is assumed that all data types being used can be cleanly converted to valid String representations using "str()"
    • This may not be true for some data types, or you may wish to handle some data types differently e.g. Dates
  • Dates should probably be handled differently, to ensure the full date and time values are output
    • You could execute an "ALTER SESSION" SQL statement to set the value of NLS_DATE_FORMAT to something suitable
    • Python has a native Date / Time data type, "datetime", which Oracle DATE columns are mapped to, and you could test for this
  • You could add extra functionality such as debugging / tracing messages (use the "logging" module) or other progress messages
    • You may wish to add extra counters to count the number of records and fields per record