Oracle Scratchpad

January 29, 2016

Table Scans

Filed under: Oracle,Statspack,Troubleshooting — Jonathan Lewis @ 12:49 pm GMT Jan 29,2016

It’s amazing how easy it is to interpret a number incorrectly until the point comes where you have to look at it closely – and then you realise that there was a lot more to the number than your initial casual assumption, and you would have realised it all along if you’d ever needed to think about it before.

Here’s a little case in point. I have a simple (i.e. non-partitioned) heap table t1 which is basically a clone of the view dba_segments, and I’ve just connected to Oracle through an SQL*Plus session then run a couple of SQL statements. The following is a continuous log of my activity:


SQL> select table_name, partitioned, blocks from user_tables;

TABLE_NAME           PAR     BLOCKS
-------------------- --- ----------
T1                   NO         958

1 row selected.

SQL> select name, value from v$mystat ms, v$statname sn where ms.statistic# = sn.statistic# and name like '%table scan%';

NAME                                  VALUE
-------------------------------- ----------
table scans (short tables)                9
table scans (long tables)                 0
table scans (rowid ranges)                0
table scans (cache partitions)            0
table scans (direct read)                 0
table scan rows gotten                 4188
table scan blocks gotten                 14

7 rows selected.

SQL> select count(extents) from t1;

COUNT(EXTENTS)
--------------
          5143

1 row selected.

SQL> select name, value from v$mystat ms, v$statname sn where ms.statistic# = sn.statistic# and name like '%table scan%';

  • My cache size is quite small, so t1 doesn’t count as a “short” table.
  • I’ve collected stats on the table (and there are no indexes) so the optimizer doesn’t need to do any dynamic sampling to generate an execution plan.
  • This is 11g, so there are no SQL Plan Directives in place to force dynamic sampling

So here’s the question: how many “table scans (long tables)” will Oracle record against my session when I re-run that query against v$mystat ?

Warning – this IS a trick question.

Update number 1

I said it was a trick question and, as you will have seen if you’ve had time to read the comments, the answer is going to depend on various configuration options. Here’s what I got in my test – and I’ve reported not just the session stats, but the segment statistics (v$segment_statistics):


NAME                                  VALUE
-------------------------------- ----------
table scans (short tables)                9
table scans (long tables)                26
table scans (rowid ranges)               26
table scans (cache partitions)            0
table scans (direct read)                 0
table scan rows gotten                 9331
table scan blocks gotten                954

7 rows selected.

SQL> select owner, object_name, object_type, value  from v$segment_statistics where owner = 'TEST_USER' and statistic_name = 'segment scans' and value != 0;

OWNER           OBJECT_NAME          OBJECT_TYPE             VALUE
--------------- -------------------- ------------------ ----------
TEST_USER       T1                   TABLE                      26

1 row selected.

I recorded 26 long table scans – and that 26 was echoed in the segment statistics. (Note: I don’t normally use v$segment_statistics, which is a join between a couple of in-memory structures and three real table, I usually query v$segstat). It’s the segment statistics that made me pause in a recent problem review;  up to that moment I had been using the “Segments by Table Scans” section of the AWR Report as a useful (but badly named – since it also counts (most) index fast full scans) indicator of a potential threat, then I suddenly realised that there was yet another important detail I had to check before I could determine what the numbers were telling me.

So the next question is WHY has Oracle reported 26 tablescans ?

Update number 2

Martin Preiss (see comments) has been working hard to investigate this, and managed to produce a couple more variations in statistics for “the same” problem. In my case I had declared the table as “parallel 2”. For a table of degree N Oracle is very likely to break the table into 13*N chunks – there’s a historic reason for 13 – and that’s why I see 26 “rowid range” scans which, unfortunately, are also recorded as “long” table scans even though each is individually well short of the short table limit. This is really annoying when you start to look at the “Segments by Table Scan” report buecause you now don’t know how many times a table really was scanned unless you know something about the run-time degree of parellelism involved.

If you check the hidden parameters you will find several parameters relating to this chunking, in particular:


_px_min_granules_per_slave        minimum number of rowid range granules to generate per slave (default  13)
_px_max_granules_per_slave        maximum number of rowid range granules to generate per slave (default 100)

Technically, therefore, Oracle MIGHT get to 100 granules per parallel slave, and a tablescan at degree 2 could be recorded as 200 tablescans!

Martin asked why my 26 tablescans didn’t show up as “table scans (direct read)” – but that’s 11g for you, it allows a serial tablescan to use direct path reads, and it allows parallel tablescans to read into the cache, and the combination of cache size and table size meant that my example just happened to read into the cache.

And that introduces ANOTHER interpretation problem – what annoying things might I discover if I declare the table the the CACHE option ? (as Ivica suggested in his first comment below) ?

Final Update (probably)

Iviva has been busy on checking the CACHE operation and shown that there are a number of cases to consider (more, in fact, than I was planning to mention – and the variation the combination in NOPARALLEL and CACHE should give you some pause for thought). The only point I wanted to make was the effect of enabling PARALLEL and CACHE; I don’t think that this is a combination that is very likely to appear in a production system, but boundary conditions (and accidents) do occur. With my little sample – even after I grew the table to be MUCH larger, the tablescan DIDN’T get reported: here are some session stats and segment stats (taken using my snapshot code) of a single tablescan running parallel 2 when the table was cached:


Name                                                                     Value
----                                                                     -----
table scans (rowid ranges)                                                  26
table scans (cache partitions)                                              26
table scan rows gotten                                                 164,672
table scan blocks gotten                                                29,611

  Statistic                                    Value
  ---------                             ------------

T1
  logical reads                               30,272
  physical reads                              29,614
  physical read requests                         261

I know I’ve done a tablescan in 26 pieces (parallel 2) – and scanned 29,000+ blocks doing it; but according to the segment stats AND session stats I haven’t done a tablescan. Fortunately, of course, I can see the parallel tablescan in the session stats, and in this isolated case I can see from the “cache partitions” statistics that that tablescan was on a cached table. But if I’ve been depending on the segment stats to tell me about which tablescans happen most frequently and do most work I’ve found another reason why I can’t trust the stats and have to do more work cross-checking different parts of the AWR for self-consistent results.

I don’t expect to add any more comments about this mixture of tablescans and parallelism, with the varying effects on the session and segment statistics – but there’s always the possibility that one day I’ll start to worry about how the KEEP and RECYCLE (db_keep_cache_size and db_recycle_cache_size) could confuse things further.

Footnote:

It’s probably worth pointing out that the segment statistics have never recorded SHORT tablescans, they’ve only ever captured details of LONG tablescans. There is a slight inconsistency here, though, since they capture all the “index fast full scans (full)” reported in the session stats whether they are short or long – not that the session stats record the difference; unfortunately, another flaw creeps in: parallel index fast full scans “disappear” from the stats, although they show up as “index fast full scans (rowid ranges)” and “index fast full scans (direct)” with the same multiplier of 13 that we see for parallel table scans.

16 Comments »

  1. I didn’t check -but: maybe 0 if the full table scan uses direct path reads (if this scan appears under “table scans (direct read)”)?

    Comment by Martin Preiss — January 29, 2016 @ 2:18 pm GMT Jan 29,2016 | Reply

    • Martin,

      That’s an interesting thought, and given the number of possible ways in which Oracle can exercise a full tablescan one that’s worth checking.

      Comment by Jonathan Lewis — January 29, 2016 @ 5:28 pm GMT Jan 29,2016 | Reply

      • Jonathan,

        it seems that serial full table scans using direct path reads are counted two times: as table scans (long tables) and as table scans (direct read). At least that’s what I see in 11.2.0.1:

        create table t1 pctfree 90 pctused 10 as select * from dba_segments;
        insert into t1 select * from t1;
        --> repeated until I got over a number of blocks > _small_table_threshold * 5
        exec dbms_stats.gather_table_stats(user, 't1')
        
        NAME                                                                  VALUE
        ---------------------------------------------------------------- ----------
        table scans (short tables)                                                5
        table scans (long tables)                                                 0
        table scans (rowid ranges)                                                0
        table scans (cache partitions)                                            0
        table scans (direct read)                                                 0
        table scan rows gotten                                                  148
        table scan blocks gotten                                                  5
        
        select count(extents) from t1;
        
        COUNT(EXTENTS)
        --------------
                 92352
        
        NAME                                                                  VALUE
        ---------------------------------------------------------------- ----------
        table scans (short tables)                                                5
        table scans (long tables)                                                 1
        table scans (rowid ranges)                                                0
        table scans (cache partitions)                                            0
        table scans (direct read)                                                 0
        table scan rows gotten                                                92500
        table scan blocks gotten                                              17230
        
        alter system flush buffer_cache;
        
        select count(extents) from t1;
        
        COUNT(EXTENTS)
        --------------
                 92352
        
        NAME                                                                  VALUE
        ---------------------------------------------------------------- ----------
        table scans (short tables)                                                5
        table scans (long tables)                                                 2
        table scans (rowid ranges)                                                0
        table scans (cache partitions)                                            0
        table scans (direct read)                                                 1
        table scan rows gotten                                               184852
        table scan blocks gotten                                              34455
        

        That at least something I never thought about.

        Regards

        Martin

        Comment by Martin Preiss — January 29, 2016 @ 6:34 pm GMT Jan 29,2016 | Reply

        • Martin,

          One of the common problems with reading AWR / Statspack reports is working out whether two numbers should be added, or if one of them is a subset of the other, or whether there are so many possible code paths that there is a partial overlap between the two figures.

          Comment by Jonathan Lewis — January 29, 2016 @ 7:32 pm GMT Jan 29,2016

        • I created a table the same way Martin did. When I tested, I found some interesting results:

          Connected to:
          Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
          With the Partitioning, OLAP, Data Mining and Real Application Testing options
           
          SQL> select name, value from V$mystat mst, v$statname snm where mst.statistic#=s
          nm.statistic# and snm.name like '%table scans%';
           
          NAME                                                                  VALUE
          ---------------------------------------------------------------- ----------
          table scans (short tables)                                                5
          table scans (long tables)                                                 0
          table scans (rowid ranges)                                                0
          table scans (cache partitions)                                            0
          table scans (direct read)                                                 0
           
          SQL> select count(extents) from t2;
           
          COUNT(EXTENTS)
          --------------
                  399385
           
          SQL> select name, value from V$mystat mst, v$statname snm where mst.statistic#=s
          nm.statistic# and snm.name like '%table scans%';
           
          NAME                                                                  VALUE
          ---------------------------------------------------------------- ----------
          table scans (short tables)                                                6
          table scans (long tables)                                                 0
          table scans (rowid ranges)                                                0
          table scans (cache partitions)                                            0
          table scans (direct read)                                                 0
           
          SQL> select /* AS */ count(extents) from t2;
           
          COUNT(EXTENTS)
          --------------
                  399385
           
          SQL> select name, value from V$mystat mst, v$statname snm where mst.statistic#=s
          nm.statistic# and snm.name like '%table scans%';
           
          NAME                                                                  VALUE
          ---------------------------------------------------------------- ----------
          table scans (short tables)                                                6
          table scans (long tables)                                                 1
          table scans (rowid ranges)                                                0
          table scans (cache partitions)                                            0
          table scans (direct read)                                                 0
           
          SQL>
          
          

          Comment by Arian — January 29, 2016 @ 7:45 pm GMT Jan 29,2016

        • Arian,

          Another interesting little detail – whenever you start to look closely you almost always end up discovering something new.

          I haven’t noticed this happening before, but my starting hypothesis would be that Oracle decided the table was a short table based on the object statistics (user_tables.blocks) – but that the run-time tablescan showed Oracle that (thanks to the randomised formatting due to ASSM) the HWM was a lot further out than the used block count indicated. It would have been interesting to see the number of tablescan blocks read – did Oracle change the way it counted when it moved from cache reads to direct path reads.

          Comment by Jonathan Lewis — January 29, 2016 @ 7:59 pm GMT Jan 29,2016

        • Hi Jonathan,

          the measurement does seem to be a bit funny. I tried to trace both statements. But with trace enabled, it always counts a table scans (long tables), for both statements. Without tracing, it counts a table scans (short tables) from the uncommented query and a table scans (long tables) for the commented query.

          I will look into this a bit more. But first trying to find out where the 26 segment scans come from.

          Comment by Arian — January 29, 2016 @ 8:17 pm GMT Jan 29,2016

  2. If the table is cached with “alter table … cache” it would be (“forced”) considered as short table and therefore you should see 0 on “table scans (long tables)”.

    Ivica

    Comment by Ivica Arsov — January 29, 2016 @ 4:14 pm GMT Jan 29,2016 | Reply

    • Ivica,

      Interesting – I hadn’t noticed that before (I think). I wonder how many other related statistics change at the same time – and does it report as as “short table”, or does it simply disappear ? If so, under what circumstances.

      Comment by Jonathan Lewis — January 29, 2016 @ 5:31 pm GMT Jan 29,2016 | Reply

      • Hi Jonathan,

        This is what I’ve discovered from my morning test cases :)
        It depends on table definition wether it is defined as parallel/cache, parallel/nocache, noparallel/cache, noparallel/nocache.

        1. Table with noparallel definition:

        1a) CACHE: table scans should appear as table scans (short tables)
        *However if table blocks (after gather_table_stats) > (_small_table_thresholds * 5) – table scans will appear as table scans (cache partitions)

        1b) NOCACHE: table scans should show as table scans (long tables)

        2. Table with parallel definition, as in your case with “parallel 2”

        1a) CACHE: table scans should show as table scans (cache partitions)
        table scans always appear as (cache partitions) regardless of “table blocks (after gather_table_stats) > (_small_table_thresholds * 5)”

        2b) NOCACHE: table scans should show as table scans (long tables)

        Comment by Ivica Arsov — January 30, 2016 @ 12:18 pm GMT Jan 30,2016 | Reply

  3. For 958 blocks, the count of 5143 is rather low. That means that there are a lot of null values in the extents column, or there are a lot of (mostly) empty blocks. (Assuming a regular 8K block size)
    I am still considering if and how this can influence the “table scans (long tables)” count.

    Comment by Arian — January 29, 2016 @ 5:23 pm GMT Jan 29,2016 | Reply

    • Arian,

      Very observant – it was a copy of the dba_segments table so extents was never null; but I’d forgotten that I moved the table after changing pctfree to 90 – the table was left over from another test where I’d been playing around with row migration etc.

      Comment by Jonathan Lewis — January 29, 2016 @ 5:33 pm GMT Jan 29,2016 | Reply

  4. after I did realize that I didn’t have an idea of the exact semantics of “table scans (rowid ranges)” I looked at https://docs.oracle.com/cd/B28359_01/server.111/b28320/stats002.htm#i375475 and found there “During parallel query, the number of table scans conducted with specified ROWID ranges”. So maybe the 26 is the number of parallel slaves accessing the table?

    Comment by Martin Preiss — January 29, 2016 @ 8:54 pm GMT Jan 29,2016 | Reply

    • with parallel query I had to add some rows before the table scan was again classified under “table scans (long tables)”:

      -- still 11.2.0.1
      insert into t1 select * from t1; -- again
      select /*+ parallel (2) */ count(extents) from t1;
      COUNT(EXTENTS)
      --------------
              738816
      
      select name, value from v$mystat ms, v$statname sn where ms.statistic# = sn.statistic# and name like '%table scan%';
      NAME                                                                  VALUE
      ---------------------------------------------------------------- ----------
      table scans (short tables)                                                5
      table scans (long tables)                                                26
      table scans (rowid ranges)                                               26
      table scans (cache partitions)                                            0
      table scans (direct read)                                                26
      table scan rows gotten                                               738964
      table scan blocks gotten                                             137833
      
      select * from V$PQ_SESSTAT;
      
      STATISTIC                      LAST_QUERY SESSION_TOTAL
      ------------------------------ ---------- -------------
      Queries Parallelized                    1             1
      DML Parallelized                        0             0
      DDL Parallelized                        0             0
      DFO Trees                               1             1
      Server Threads                          2             0
      Allocation Height                       2             0
      Allocation Width                        1             0
      Local Msgs Sent                        58            58
      Distr Msgs Sent                         0             0
      Local Msgs Recv'd                      58            58
      Distr Msgs Recv'd                       0             0
      
      ----------------------------------------------------------------------------------------------------------------
      | Id  | Operation              | Name     | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |
      ----------------------------------------------------------------------------------------------------------------
      |   0 | SELECT STATEMENT       |          |     1 |     4 |  4786   (0)| 00:00:24 |        |      |            |
      |   1 |  SORT AGGREGATE        |          |     1 |     4 |            |          |        |      |            |
      |   2 |   PX COORDINATOR       |          |       |       |            |          |        |      |            |
      |   3 |    PX SEND QC (RANDOM) | :TQ10000 |     1 |     4 |            |          |  Q1,00 | P->S | QC (RAND)  |
      |   4 |     SORT AGGREGATE     |          |     1 |     4 |            |          |  Q1,00 | PCWP |            |
      |   5 |      PX BLOCK ITERATOR |          | 92352 |   360K|  4786   (0)| 00:00:24 |  Q1,00 | PCWC |            |
      |   6 |       TABLE ACCESS FULL| T1       | 92352 |   360K|  4786   (0)| 00:00:24 |  Q1,00 | PCWP |            |
      ----------------------------------------------------------------------------------------------------------------
      
      Note
      -----
         - Degree of Parallelism is 2 because of hint
      

      So the 26 is apparently not the number of parallel processes – but rather the number of rowid ranges scanned by the parallel slaves. Taking a look at the sql monitor the 26 appears for execs.

      SQL Text
      ------------------------------
      select /*+ monitor parallel (2) */ count(extents) from t1
      
      Global Information
      ------------------------------
       Status              :  DONE (ALL ROWS)
       Instance ID         :  1
       Session             :  TEST (12:4)
       SQL ID              :  4vpusb9690znn
       SQL Execution ID    :  16777216
       Execution Started   :  01/29/2016 22:13:48
       First Refresh Time  :  01/29/2016 22:13:48
       Last Refresh Time   :  01/29/2016 22:14:02
       Duration            :  14s
       Module/Action       :  SQL*Plus/-
       Service             :  testdb
       Program             :  sqlplus.exe
       Fetch Calls         :  1
      
      Global Stats
      ===================================================================================================
      | Elapsed | Queuing |   Cpu   |    IO    | Concurrency |  Other   | Fetch | Buffer | Read | Read  |
      | Time(s) | Time(s) | Time(s) | Waits(s) |  Waits(s)   | Waits(s) | Calls |  Gets  | Reqs | Bytes |
      ===================================================================================================
      |      29 |    0.00 |    0.58 |       29 |        0.01 |     0.14 |     1 |   207K | 1105 |   1GB |
      ===================================================================================================
      
      Parallel Execution Details (DOP=2 , Servers Allocated=2)
      ======================================================================================================================================================
      |      Name      | Type  | Server# | Elapsed | Queuing |   Cpu   |    IO    | Concurrency |  Other   | Buffer | Read | Read  |      Wait Events      |
      |                |       |         | Time(s) | Time(s) | Time(s) | Waits(s) |  Waits(s)   | Waits(s) |  Gets  | Reqs | Bytes |      (sample #)       |
      ======================================================================================================================================================
      | PX Coordinator | QC    |         |    0.01 |    0.00 |         |          |        0.01 |     0.00 |      5 |      |     . |                       |
      | p000           | Set 1 |       1 |      14 |         |    0.25 |       14 |             |     0.09 |   101K |  553 | 538MB | direct path read (14) |
      | p001           | Set 1 |       2 |      15 |         |    0.33 |       14 |             |     0.05 |   106K |  552 | 538MB | direct path read (15) |
      ======================================================================================================================================================
      
      SQL Plan Monitoring Details (Plan Hash Value=3110199320)
      =======================================================================================================================================================
      | Id |        Operation         |   Name   |  Rows   | Cost |   Time    | Start  | Execs |   Rows   | Read | Read  | Activity |    Activity Detail    |
      |    |                          |          | (Estim) |      | Active(s) | Active |       | (Actual) | Reqs | Bytes |   (%)    |      (# samples)      |
      =======================================================================================================================================================
      |  0 | SELECT STATEMENT         |          |         |      |         1 |    +14 |     1 |        1 |      |       |          |                       |
      |  1 |   SORT AGGREGATE         |          |       1 |      |         1 |    +14 |     1 |        1 |      |       |          |                       |
      |  2 |    PX COORDINATOR        |          |         |      |         1 |    +14 |     3 |        2 |      |       |          |                       |
      |  3 |     PX SEND QC (RANDOM)  | :TQ10000 |       1 |      |         1 |    +14 |     2 |        2 |      |       |          |                       |
      |  4 |      SORT AGGREGATE      |          |       1 |      |        13 |     +2 |     2 |        2 |      |       |          |                       |
      |  5 |       PX BLOCK ITERATOR  |          |   92352 | 4786 |        13 |     +2 |     2 |     739K |      |       |          |                       |
      |  6 |        TABLE ACCESS FULL | T1       |   92352 | 4786 |        15 |     +1 |    26 |     739K | 1105 |   1GB |   100.00 | direct path read (29) |
      =======================================================================================================================================================
      

      So it seems that parallel query ruins this statistic…

      Comment by Martin Preiss — January 29, 2016 @ 9:19 pm GMT Jan 29,2016 | Reply

      • but then – why does your result not contain “table scans (direct read)”. Obviously I am missing something…

        Comment by Martin Preiss — January 29, 2016 @ 9:22 pm GMT Jan 29,2016 | Reply

        • rebuilding the example with the most simple setup I finally get your numbers:

          create table t1 pctfree 90 pctused 10 as select * from dba_segments;
          exec dbms_stats.gather_table_stats(user, 'T1')
          --> reconnect
          NAME                                                                  VALUE
          ---------------------------------------------------------------- ----------
          table scans (short tables)                                                5
          table scans (long tables)                                                 0
          table scans (rowid ranges)                                                0
          table scans (cache partitions)                                            0
          table scans (direct read)                                                 0
          table scan rows gotten                                                  148
          table scan blocks gotten                                                  5
          
          select /*+ parallel (2) */ count(extents) from t1;
          
          COUNT(EXTENTS)
          --------------
                    5775
          
          
          NAME                                                                  VALUE
          ---------------------------------------------------------------- ----------
          table scans (short tables)                                                5
          table scans (long tables)                                                26
          table scans (rowid ranges)                                               26
          table scans (cache partitions)                                            0
          table scans (direct read)                                                 0
          table scan rows gotten                                                 5923
          table scan blocks gotten                                               1058
          

          Comment by Martin Preiss — January 29, 2016 @ 9:34 pm GMT Jan 29,2016


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Blog at WordPress.com.