Forum Stats

  • 3,768,015 Users
  • 2,252,740 Discussions
  • 7,874,413 Comments

Discussions

Query very slow when querying by a specific value in a specific column

So here I have this very simple table, designed not in the best way imo but that's a different topic.

SQL> describe batch_log

 Name       Null?  Type

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

 REQUEST_ID    NOT NULL NUMBER(7)

 LINE_NO      NOT NULL NUMBER

 TEXT            VARCHAR2(4000)

 LOG_DATE          DATE

This table has an INDEX based on REQUEST_ID and LINE_NO columns.

When I run Q1 result comes back in a whim. When I run the query based on another REQUEST_ID the query takes 5+ minutes.

Q1: SELECT REQUEST_ID as "REQUEST_ID" , LINE_NO as "LINE_NO" , TEXT as "TEXT" , LOG_DATE as "LOG_DATE" FROM BATCH_LOG WHERE REQUEST_ID=5061 ORDER BY line_no;

Q2: SELECT REQUEST_ID as "REQUEST_ID" , LINE_NO as "LINE_NO" , TEXT as "TEXT" , LOG_DATE as "LOG_DATE" FROM BATCH_LOG WHERE REQUEST_ID=5060 ORDER BY line_no;

Execution plan looks exactly the same for both in num or rows and CPU cost. I ran the query with autotrace and also ran gather_stats on that particular table but still I don't understand why when I have REQUEST_ID=5060 there's millions of physical reads on the disk.

Predicate Information (identified by operation id):

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

  2 - access("REQUEST_ID"=5060)

Statistics

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

     0 recursive calls

     0 db block gets

  2465841 consistent gets

  2465833 physical reads

     0 redo size

    980 bytes sent via SQL*Net to client

    516 bytes received via SQL*Net from client

     2 SQL*Net roundtrips to/from client

     0 sorts (memory)

     0 sorts (disk)

     2 rows processed


Could it be the DB_CACHE size is undersized (400M)? I mean, I do think that SGA (2G) and PGA (2G) are tremendously undersized but I'm new to the company and I'm trying to push changes as quickly (and "politely") as I can.

Thoughts on DB_CACHE being undersized causing this problem?

Best Answer

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,786 Gold Crown
    Accepted Answer


    When you say you see a 250k empty block from the stats above, which value are you referring to, free buffer inspected? Thanks for your help.

    You've shown a plan which is an index range scan - so that's a starting point. There were no predicates other than the one driving the range scan, so you weren't doing a big range scan then discarding a huge amount of data after visiting the table. But you were only returning 2 rows.

    Then there were four consecutive stats

    physical reads                          2465847
    physical reads cache                    2465847
    physical read IO requests               2465847
    physical read bytes                  5050054656
    

    You've read 2,465,847 (without the commas I was out by a factor of 10) blocks into the cache using the same number of I/O requests: so you're doing lots of single block reads. (The 5,050,054,656 bytes was how I derived 2KB blocks).

    You don't have any statistics about "undo records applied", so these are not huge numbers of blocks being read from the undo tablespace; i.e. there's no read-consistency work, no delayed block cleanout, no commit-time checking going on.

    For an extra confirming detail, there were no "table scan (long tables)" in the stats.

    Regards

    Jonathan Lewis

    Astro313saratpvv

Answers

  • saratpvv
    saratpvv Member Posts: 905 Gold Badge

    What is size of the table?

    REQUEST_ID is unique index? if yes why then order by clause ?

  • EdStevens
    EdStevens Member Posts: 28,519 Gold Crown

    REQUEST_ID is unique index? if yes why then order by clause ?

    IF request_id has a unique index, then valid question. But I see no indication that is is, in fact, a unique index.

  • Solomon Yakobson
    Solomon Yakobson Member Posts: 18,905 Red Diamond
    edited Jun 25, 2021 5:41PM

    And whot results do you get for:

    SELECT COUNT(*),SUM(LENGTH(TEXT)) FROM BATCH_LOG WHERE REQUEST_ID=5061;
    SELECT COUNT(*),SUM(LENGTH(TEXT)) FROM BATCH_LOG WHERE REQUEST_ID=5060;
    

    Also, provide execution plans for both statements.

    SY.

  • Astro313
    Astro313 Member Posts: 16 Blue Ribbon

    @saratpvv REQUEST_ID is not an Index. Index is the combination of RQUEST_ID and LINE_NO. One REQUEST_ID can have multiple lines that's why they use the order by clause

    The size of the table is: 9.6GB


    @Solomon Yakobson

    SELECT COUNT(*),SUM(LENGTH(TEXT)) FROM BATCH_LOG WHERE REQUEST_ID=5061; --QUICK 

     COUNT(*) SUM(LENGTH(TEXT))

        12        476


    SELECT COUNT(*),SUM(LENGTH(TEXT)) FROM BATCH_LOG WHERE REQUEST_ID=5060;--SLOW

     COUNT(*) SUM(LENGTH(TEXT))

         2        111




    I gathered stats for the execution plan for both queries.


    *******FOR REQUEST_ID=5061 QUICK*********

    PLAN_TABLE_OUTPUT

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

    SQL_ID gcq4r8vt1g6w3, child number 1

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

    SELECT COUNT(*),SUM(LENGTH(TEXT)) FROM BATCH_LOG WHERE REQUEST_ID=5061


    Plan hash value: 1987396561


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

    | Id | Operation              | Name     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time  | A-Rows |  A-Time  | Buffers |

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

    |  0 | SELECT STATEMENT           |       |   1 |    |    |   7 (100)|     |   1 |00:00:00.01 |   10 |

    |  1 | SORT AGGREGATE           |       |   1 |   1 |  44 |      |     |   1 |00:00:00.01 |   10 |


    PLAN_TABLE_OUTPUT

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

    |  2 |  TABLE ACCESS BY INDEX ROWID BATCHED| BATCH_LOG  |   1 |   37 | 1628 |   7  (0)| 00:00:01 |   12 |00:00:00.01 |   10 |

    |* 3 |  INDEX RANGE SCAN         | BATCH_LOG_I1 |   1 |   37 |    |   5  (0)| 00:00:01 |   12 |00:00:00.01 |    6 |

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


    Query Block Name / Object Alias (identified by operation id):

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


      1 - SEL$1

      2 - SEL$1 / [email protected]$1

      3 - SEL$1 / [email protected]$1



    PLAN_TABLE_OUTPUT

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

    Outline Data

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


     /*+

       BEGIN_OUTLINE_DATA

       IGNORE_OPTIM_EMBEDDED_HINTS

       OPTIMIZER_FEATURES_ENABLE('19.1.0')

       DB_VERSION('19.1.0')

       ALL_ROWS

       OUTLINE_LEAF(@"SEL$1")

       INDEX_RS_ASC(@"SEL$1" "BATCH_LOG"@"SEL$1" ("BATCH_LOG"."REQUEST_ID" "BATCH_LOG"."LINE_NO"))


    PLAN_TABLE_OUTPUT

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

       BATCH_TABLE_ACCESS_BY_ROWID(@"SEL$1" "BATCH_LOG"@"SEL$1")

       END_OUTLINE_DATA

     */


    Predicate Information (identified by operation id):

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


      3 - access("REQUEST_ID"=5061)


    Column Projection Information (identified by operation id):

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


    PLAN_TABLE_OUTPUT

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



    *******FOR REQUEST_ID=5060 SLOW*********


    PLAN_TABLE_OUTPUT

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

    SQL_ID aux5hgc1582ut, child number 1

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

    SELECT COUNT(*),SUM(LENGTH(TEXT)) FROM BATCH_LOG WHERE REQUEST_ID=5060


    Plan hash value: 1987396561


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

    | Id | Operation              | Name     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time  | A-Rows |  A-Time  | Buffers | Reads |

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

    |  0 | SELECT STATEMENT           |       |   1 |    |    |   7 (100)|     |   1 |00:25:22.60 |  2465K|  2430K|

    |  1 | SORT AGGREGATE           |       |   1 |   1 |  44 |      |     |   1 |00:25:22.60 |  2465K|  2430K|


    PLAN_TABLE_OUTPUT

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

    |  2 |  TABLE ACCESS BY INDEX ROWID BATCHED| BATCH_LOG  |   1 |   37 | 1628 |   7  (0)| 00:00:01 |   2 |00:25:22.60 |  2465K|  2430K|

    |* 3 |  INDEX RANGE SCAN         | BATCH_LOG_I1 |   1 |   37 |    |   5  (0)| 00:00:01 |   2 |00:25:22.60 |  2465K|  2430K|

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

    Query Block Name / Object Alias (identified by operation id):

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


      1 - SEL$1

      2 - SEL$1 / [email protected]$1

      3 - SEL$1 / [email protected]$1



    PLAN_TABLE_OUTPUT

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

    Outline Data

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


     /*+

       BEGIN_OUTLINE_DATA

       IGNORE_OPTIM_EMBEDDED_HINTS

       OPTIMIZER_FEATURES_ENABLE('19.1.0')

       DB_VERSION('19.1.0')

       ALL_ROWS

       OUTLINE_LEAF(@"SEL$1")

       INDEX_RS_ASC(@"SEL$1" "BATCH_LOG"@"SEL$1" ("BATCH_LOG"."REQUEST_ID" "BATCH_LOG"."LINE_NO"))


    PLAN_TABLE_OUTPUT

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

       BATCH_TABLE_ACCESS_BY_ROWID(@"SEL$1" "BATCH_LOG"@"SEL$1")

       END_OUTLINE_DATA

     */


    Predicate Information (identified by operation id):

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


      3 - access("REQUEST_ID"=5060)


    Column Projection Information (identified by operation id):

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


    PLAN_TABLE_OUTPUT

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


      1 - (#keys=0) COUNT(*)[22], SUM(LENGTH("TEXT"))[22]

      2 - "TEXT"[VARCHAR2,4000]

      3 - "BATCH_LOG".ROWID[ROWID,10]



    49 rows selected.


    I could see the disk reads going up and staying high while running the second query. This time took about 20 mins. Oracle its not working hard at all at the CPU.

    Thanks Astro

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,786 Gold Crown
    edited Jun 25, 2021 8:31PM


    I can think of two reasons why you might see an oddity like this; but let's find out what those disc reads are before we go any further.

    Connect with a new session.

    Run the slow query, then

    select
            name, value
    from
            v$statname      sn,
            v$mystat        ms
    where
            ms.value != 0
    and     sn.statistic# = ms.statistic#
    ;
    

    Post the results - it will give us some idea of what is happening.

    If you want to check https://jonathanlewis.wordpress.com/my-stats/ there are two more queries (if you're allowed to access the views) that will tell us a little more - but this one is likely to be the most informative.

    Regards

    Jonathan Lewis


    To post text in fixed format: click the paragraph symbol (backwards P) to the left of the edit box, select the "quote marks" option from the pop-up, then the "code block" option from the resulting drop-down. If you highlight multiple paragraphs before doing this they will be grouped into a single code block.

  • Astro313
    Astro313 Member Posts: 16 Blue Ribbon
    select
      name, value
    from
      v$statname sn,
      v$mystat ms
    where ms.value != 0
    and sn.statistic# = ms.statistic#;
    

    Hey @Jonathan Lewis the machine gets restarted every Saturday night so I reran the 2 queries manually again. 1 took no time the other 27mins 30sec.

    SQL> select
     2   name, value
     3 from
     4   v$statname sn,
     5   v$mystat ms
     6 where ms.value != 0
     7 and sn.statistic# = ms.statistic#;
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    Requests to/from client                         12
    logons cumulative                             1
    logons current                              1
    opened cursors cumulative                        64
    opened cursors current                          3
    user calls                                17
    recursive calls                             501
    pinned cursors current                          1
    user logons cumulative                          1
    session logical reads                        2466121
    CPU used when call started                       6363
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    CPU used by this session                        6363
    DB time                               165180
    user I/O wait time                          159245
    non-idle wait time                          159245
    non-idle wait count                         2465903
    session connect time                       1624884082
    process last non-idle time                    1624885814
    session uga memory                         2272512
    session uga memory max                       2272512
    messages sent                               3
    session pga memory                         4317080
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    session pga memory max                       4317080
    enqueue requests                             16
    enqueue releases                             15
    physical read total IO requests                   2465847
    physical read total bytes                    5050054656
    cell physical IO interconnect bytes               5050054656
    db block gets                               6
    db block gets from cache                         6
    db block gets from cache (fastpath)                    5
    consistent gets                           2466115
    consistent gets from cache                     2466115
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    consistent gets pin                         2465974
    consistent gets pin (fastpath)                     136
    consistent gets examination                       141
    consistent gets examination (fastpath)                 132
    logical read bytes from cache                  5050615808
    physical reads                           2465847
    physical reads cache                        2465847
    physical read IO requests                      2465847
    physical read bytes                       5050054656
    db block changes                             8
    free buffer requested                        2465848
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    dirty buffers inspected                         880
    pinned buffers inspected                         58
    hot buffers moved to head of LRU                   92357
    free buffer inspected                        2465583
    commit cleanouts                             2
    commit cleanouts successfully completed                  2
    switch current to new buffer                       1
    switch current caused by our pin                     1
    prefetched blocks aged out before use                  72
    shared hash latch upgrades - no wait                 525808
    calls to kcmgcs                             18
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    calls to kcmgas                              2
    calls to get snapshot scn: kcmgss                    68
    redo entries                               4
    redo size                               1628
    redo synch time (usec)                         562
    redo synch time overhead (usec)                     17
    redo synch time overhead count ( 2ms)                  1
    redo synch writes                             1
    redo write info find                           1
    file io wait time                        1592444328
    undo change vector size                         320
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    no work - consistent read gets                   2465968
    deferred (CURRENT) block cleanout applications              2
    blocks cleaned out using minact                      1
    table scans (short tables)                        1
    table scan rows gotten                          5
    table scan disk non-IMC rows gotten                    5
    table scan blocks gotten                         1
    table fetch by rowid                           84
    table fetch continued row                         3
    cluster key scans                            16
    cluster key scan block gets                       18
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    rows fetched via callback                         5
    index fetch by key                            24
    index range scans                            63
    HSC Heap Segment Block Changes                      2
    Heap Segment Array Updates                        1
    session cursor cache hits                        30
    session cursor cache count                        17
    cursor authentications                          2
    buffer is pinned count                          99
    buffer is not pinned count                       184
    workarea memory allocated                       1606
    
    NAME                                 VALUE
    ---------------------------------------------------------------- ----------
    workarea executions - optimal                      17
    parse time elapsed                            5
    parse count (total)                           44
    parse count (hard)                            3
    execute count                              63
    bytes sent via SQL*Net to client                    5977
    bytes received via SQL*Net from client                 4033
    SQL*Net roundtrips to/from client                    12
    sorts (memory)                              33
    sorts (rows)                              102
    
    98 rows selected.
    
    Elapsed: 00:00:00.21
    SQL>
    
  • Astro313
    Astro313 Member Posts: 16 Blue Ribbon

    Hi @Jonathan Lewis . I logged off the sessions, logged in and ran the stats query you had on your website.


    SQL> 
    SQL> set linesize 200
    SQL> select
     2     name, value
     3 from
     4     v$statname   sn,
     5     v$mystat    ms
     6 where
     7     ms.value != 0
     8 and   sn.statistic# = ms.statistic#
     9 ;
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    Requests to/from client                          7                                                               
    logons cumulative                             1                                                               
    logons current                              1                                                               
    opened cursors cumulative                         6                                                               
    opened cursors current                          1                                                               
    user calls                                9                                                               
    recursive calls                             19                                                               
    pinned cursors current                          1                                                               
    user logons cumulative                          1                                                               
    session logical reads                        2466540                                                               
    CPU used when call started                       4498                                                               
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    CPU used by this session                        4498                                                               
    DB time                               152796                                                               
    user I/O wait time                          147532                                                               
    non-idle wait time                          147532                                                               
    non-idle wait count                         2466136                                                               
    process last non-idle time                    1624889829                                                               
    session uga memory                         2010560                                                               
    session uga memory max                       2010560                                                               
    messages sent                              27                                                               
    session pga memory                         3456712                                                               
    session pga memory max                       3456712                                                               
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    enqueue requests                             15                                                               
    enqueue releases                             14                                                               
    physical read total IO requests                   2466087                                                               
    physical read total bytes                    5050540032                                                               
    cell physical IO interconnect bytes               5050540032                                                               
    consistent gets                           2466540                                                               
    consistent gets from cache                     2466540                                                               
    consistent gets pin                         2465821                                                               
    consistent gets pin (fastpath)                      9                                                               
    consistent gets examination                       719                                                               
    consistent gets examination (fastpath)                 126                                                               
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    logical read bytes from cache                  5051473920                                                               
    physical reads                           2466083                                                               
    physical reads cache                        2466083                                                               
    physical read IO requests                      2466083                                                               
    physical read bytes                       5050537984                                                               
    consistent changes                           716                                                               
    free buffer requested                        2466089                                                               
    dirty buffers inspected                        10324                                                               
    pinned buffers inspected                         16                                                               
    hot buffers moved to head of LRU                   21595                                                               
    free buffer inspected                        2478339                                                               
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    CR blocks created                             6                                                               
    prefetched blocks aged out before use                  201                                                               
    shared hash latch upgrades - no wait                 539273                                                               
    calls to kcmgcs                             13                                                               
    calls to get snapshot scn: kcmgss                     7                                                               
    file io wait time                        1475312867                                                               
    transaction tables consistent reads - undo records applied       694                                                               
    transaction tables consistent read rollbacks               1                                                               
    data blocks consistent reads - undo records applied           18                                                               
    no work - consistent read gets                   2465811                                                               
    rollbacks only - consistent read gets                   4                                                               
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    cleanouts and rollbacks - consistent read gets              4                                                               
    immediate (CR) block cleanout applications                4                                                               
    commit txn count during cleanout                     4                                                               
    cleanout - number of ktugct calls                     4                                                               
    table scans (short tables)                        1                                                               
    table scan rows gotten                          5                                                               
    table scan disk non-IMC rows gotten                    5                                                               
    table scan blocks gotten                         1                                                               
    table fetch by rowid                           2                                                               
    index range scans                             1                                                               
    sql area evicted                             1                                                               
    
    NAME                                 VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    CCursor + sql area evicted                        2                                                               
    session cursor cache count                        4                                                               
    buffer is not pinned count                        6                                                               
    workarea memory allocated                       1633                                                               
    parse time elapsed                            2                                                               
    parse count (total)                            6                                                               
    parse count (hard)                            1                                                               
    execute count                               5                                                               
    bytes sent via SQL*Net to client                    3470                                                               
    bytes received via SQL*Net from client                 2664                                                               
    SQL*Net roundtrips to/from client                     7                                                               
    
    77 rows selected.
    
    Elapsed: 00:00:00.11
    SQL> 
    SQL> select
     2     event, total_waits, total_timeouts, time_waited, max_wait
     3 from
     4     (select /*+ no_merge */ sid from v$mystat where rownum = 1) ms,
     5     v$session_event     se
     6 where
     7     se.sid = ms.sid
     8 ;
    
    EVENT                              TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED  MAX_WAIT                                            
    ---------------------------------------------------------------- ----------- -------------- ----------- ----------                                            
    Disk file operations I/O                         23       0      1     0                                            
    db file sequential read                       2466083       0   147531     9                                            
    SQL*Net message to client                         16       0      0     0                                            
    SQL*Net message from client                        15       0    56342   44492                                            
    events in waitclass Other                         25       1      0     0                                            
    
    Elapsed: 00:00:00.00
    SQL> 
    SQL> select
     2     stat_name, value
     3 from
     4     (select /*+ no_merge */ sid from v$mystat where rownum = 1) ms,
     5     v$sess_time_model    tm
     6 where
     7     tm.sid = ms.sid
     8 and   tm.value != 0
     9 ;
    
    STAT_NAME                               VALUE                                                               
    ---------------------------------------------------------------- ----------                                                               
    DB time                             1528365931                                                               
    DB CPU                               45162507                                                               
    parse time elapsed                           2604                                                               
    hard parse elapsed time                        1954                                                               
    sql execute elapsed time                     1527939072                                                               
    connection management call elapsed time                17729                                                               
    PL/SQL execution elapsed time                      89                                                               
    
    7 rows selected.
    
    Elapsed: 00:00:00.01
    SQL> 
    SQL> spool off
    

    I can see that the physical reads are too high and the file to wait time is also very high. I still don't understand why that happens only when I query for that specific REQUEST_ID. Would rebuilding the index resolve the issue? Also I've been thinking of increasing the SGA and DB_CACHE_SIZE associated with it.


    Thanks

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,786 Gold Crown

    @Astro313

    The figures suggest that something has left an enormous (250,000 block) hole in the middle of your index which used to hold index entries for request_id = 5060. (The reason for checking the session stats is that they might have indicated a read-consistency problem - but the absence of any "xxx - undo records applied" statistics show that this is not the case).

    An oddity of this index is that it seems to be made up of blocks sized as 2KB. Is this a special tablespace, or is the entire database running with a 2KB block size?

    An index rebuild (or possibly a coalesce) would address the issue - at least in the short term, but it would be good to find out why this had happened so that you could work out if there was any way to ensure that the problem didn't simply reappear in a little while.

    Since there (appear to be) 250,000 empty leaf blocks in the index the most significant statistic in user_indexes/dba_indexes for the size of the index (leaf_blocks) will be completely misleading - but you can confirm that the problem is empty space by comparing the size of the index segment (user/dba_segments) with the reported leaf_blocks if the stats are up to date.


    One possible explanation for the hole is that (possibly historically - you haven't supplied a version) request_id 5060 was the lowest request_id in the index and was inserting several hundred rows with increasing values for line_no each day, and then deleting them. If the next batch of inserts were for higher line_no values than the previous batch then Oracle might never get around to marking the leaf blocks with the lower values as empty.


    Regards

    Jonathan Lewis

  • Astro313
    Astro313 Member Posts: 16 Blue Ribbon

    Hey @Jonathan Lewis you're right about the size blocks, they're using (or should I say we now that I inherited this) 2k blocks since Oracle 8 I believe, have upgraded once in a while the clients DB but not the db size block, so most of the tables, other than those who contain LOBs are 2k blocks. Upgrading all of these 700+ single instance DB to 8k blocks will be another task which I'm planning right now.

    As per the oddity, someone caught a bug on the application which was trying to run something without a from/to date and that created a loop on this table and caused the issue I think.

    When you say you see a 250k empty block from the stats above, which value are you referring to, free buffer inspected? Thanks for your help.

  • Jonathan Lewis
    Jonathan Lewis Member Posts: 9,786 Gold Crown
    Accepted Answer


    When you say you see a 250k empty block from the stats above, which value are you referring to, free buffer inspected? Thanks for your help.

    You've shown a plan which is an index range scan - so that's a starting point. There were no predicates other than the one driving the range scan, so you weren't doing a big range scan then discarding a huge amount of data after visiting the table. But you were only returning 2 rows.

    Then there were four consecutive stats

    physical reads                          2465847
    physical reads cache                    2465847
    physical read IO requests               2465847
    physical read bytes                  5050054656
    

    You've read 2,465,847 (without the commas I was out by a factor of 10) blocks into the cache using the same number of I/O requests: so you're doing lots of single block reads. (The 5,050,054,656 bytes was how I derived 2KB blocks).

    You don't have any statistics about "undo records applied", so these are not huge numbers of blocks being read from the undo tablespace; i.e. there's no read-consistency work, no delayed block cleanout, no commit-time checking going on.

    For an extra confirming detail, there were no "table scan (long tables)" in the stats.

    Regards

    Jonathan Lewis

    Astro313saratpvv