Covering bases

What would you think if you receive a complaint about plan regression with the following information (from SQL real-time monitoring report) about the good plan:


Global Stats
==============================================================================
| Elapsed |   Cpu   |    IO    | Concurrency | Fetch | Buffer | Read | Read  |
| Time(s) | Time(s) | Waits(s) |  Waits(s)   | Calls |  Gets  | Reqs | Bytes |
==============================================================================
|      99 |      64 |       36 |        0.00 |     6 |    20M | 9119 |  75MB |
==============================================================================

===============================================================================================================================================================================================================
| Id |                     Operation                      |          Name           |  Rows   | Cost |   Time    | Start  | Execs |   Rows   | Read | Read  |  Mem  | Activity |       Activity Detail        |
|    |                                                    |                         | (Estim) |      | Active(s) | Active |       | (Actual) | Reqs | Bytes | (Max) |   (%)    |         (# samples)          |
===============================================================================================================================================================================================================
|  0 | SELECT STATEMENT                                   |                         |         |      |       186 |    +98 |     1 |     1062 |      |       |       |          |                              |
|  1 |   NESTED LOOPS OUTER                               |                         |       1 | 4860 |       186 |    +98 |     1 |     1062 |      |       |       |          |                              |
|  2 |    FILTER                                          |                         |         |      |       186 |    +98 |     1 |     1062 |      |       |       |          |                              |
|  3 |     NESTED LOOPS OUTER                             |                         |       1 | 4858 |       186 |    +98 |     1 |     1062 |      |       |       |          |                              |
|  4 |      NESTED LOOPS OUTER                            |                         |       5 | 4848 |       186 |    +98 |     1 |     1062 |      |       |       |          |                              |
|  5 |       VIEW                                         |                         |       5 | 4838 |       186 |    +98 |     1 |     1062 |      |       |       |          |                              |
|  6 |        WINDOW SORT PUSHED RANK                     |                         |       5 | 4838 |       186 |    +98 |     1 |     2616 |      |       |  628K |          |                              |
|  7 |         FILTER                                     |                         |         |      |         1 |    +98 |     1 |     4096 |      |       |       |          |                              |
|  8 |          HASH GROUP BY                             |                         |       5 | 4838 |        93 |     +6 |     1 |     4324 |      |       |    1M |          |                              |
|  9 |           NESTED LOOPS                             |                         |      91 | 4748 |        93 |     +6 |     1 |     4461 |      |       |       |          |                              |
| 10 |            NESTED LOOPS                            |                         |      91 |  105 |        93 |     +6 |     1 |     215K |      |       |       |          |                              |
| 11 |             TABLE ACCESS FULL                      | B                       |       1 |   88 |        93 |     +6 |     1 |      186 |    1 |  8192 |       |          |                              |
| 12 |              SORT AGGREGATE                        |                         |       1 |      |         1 |     +6 |     1 |        1 |      |       |       |          |                              |
| 13 |               TABLE ACCESS FULL                    | B                       |       1 |   88 |         1 |     +6 |     1 |      256 |      |       |       |          |                              |
| 14 |             INLIST ITERATOR                        |                         |         |      |        93 |     +6 |   186 |     215K |      |       |       |          |                              |
| 15 |              TABLE ACCESS BY GLOBAL INDEX ROWID    | A                       |     214 |   17 |        95 |     +4 |  2232 |     215K | 3028 |  24MB |       |    10.87 | db file sequential read (10) |
| 16 |               INDEX RANGE SCAN                     | A$TYPE                  |     214 |   12 |        93 |     +6 |  2232 |     215K | 1720 |  13MB |       |     7.61 | Cpu (2)                      |
|    |                                                    |                         |         |      |           |        |       |          |      |       |       |          | db file sequential read (5)  |
| 17 |            VIEW                                    |                         |       1 |   51 |        93 |     +6 |  215K |     4461 |      |       |       |          |                              |
| 18 |             UNION ALL PUSHED PREDICATE             |                         |         |      |        93 |     +6 |  215K |     4461 |      |       |       |     1.09 | Cpu (1)                      |
| 19 |              NESTED LOOPS                          |                         |       1 |    7 |        93 |     +6 |  215K |      926 |      |       |       |          |                              |
| 20 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 21 |                INDEX UNIQUE SCAN                   | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |    1 |  8192 |       |     3.26 | Cpu (3)                      |
| 22 |               PARTITION LIST ALL                   |                         |       1 |    5 |        93 |     +6 |  215K |      926 |      |       |       |     1.09 | Cpu (1)                      |
| 23 |                TABLE ACCESS BY LOCAL INDEX ROWID   | A                       |       1 |    5 |        93 |     +6 |  858K |      926 |      |       |       |     1.09 | Cpu (1)                      |
| 24 |                 INDEX RANGE SCAN                   | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K | 1735 |  14MB |       |     8.70 | Cpu (3)                      |
|    |                                                    |                         |         |      |           |        |       |          |      |       |       |          | db file sequential read (5)  |
| 25 |              NESTED LOOPS                          |                         |       1 |    7 |        93 |     +6 |  215K |      892 |      |       |       |          |                              |
| 26 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 27 |                INDEX UNIQUE SCAN                   | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |      |       |       |     1.09 | Cpu (1)                      |
| 28 |               PARTITION LIST ALL                   |                         |       1 |    5 |        93 |     +6 |  215K |      892 |      |       |       |          |                              |
| 29 |                TABLE ACCESS BY LOCAL INDEX ROWID   | A                       |       1 |    5 |        93 |     +6 |  858K |      892 |      |       |       |     4.35 | Cpu (4)                      |
| 30 |                 INDEX RANGE SCAN                   | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K |      |       |       |     6.52 | Cpu (6)                      |
| 31 |              NESTED LOOPS                          |                         |       1 |    7 |        93 |     +6 |  215K |        3 |      |       |       |     1.09 | Cpu (1)                      |
| 32 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 33 |                INDEX UNIQUE SCAN                   | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |      |       |       |     2.17 | Cpu (2)                      |
| 34 |               PARTITION LIST ALL                   |                         |       1 |    5 |         7 |    +84 |  215K |        3 |      |       |       |          |                              |
| 35 |                TABLE ACCESS BY LOCAL INDEX ROWID   | A                       |       1 |    5 |        93 |     +6 |  858K |        3 |      |       |       |     1.09 | Cpu (1)                      |
| 36 |                 INDEX RANGE SCAN                   | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K |      |       |       |     2.17 | Cpu (2)                      |
| 37 |              NESTED LOOPS                          |                         |       1 |    7 |        93 |     +6 |  215K |        3 |      |       |       |     1.09 | Cpu (1)                      |
| 38 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 39 |                INDEX UNIQUE SCAN                   | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |      |       |       |     2.17 | Cpu (2)                      |
| 40 |               PARTITION LIST ALL                   |                         |       1 |    5 |         7 |    +84 |  215K |        3 |      |       |       |          |                              |
| 41 |                TABLE ACCESS BY LOCAL INDEX ROWID   | A                       |       1 |    5 |        93 |     +6 |  858K |        3 |      |       |       |     1.09 | Cpu (1)                      |
| 42 |                 INDEX RANGE SCAN                   | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K |      |       |       |     3.26 | Cpu (3)                      |
| 43 |              NESTED LOOPS                          |                         |       1 |    7 |        93 |     +6 |  215K |       82 |      |       |       |          |                              |
| 44 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |     1.09 | Cpu (1)                      |
| 45 |                INDEX UNIQUE SCAN                   | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 46 |               PARTITION LIST ALL                   |                         |       1 |    5 |         9 |    +90 |  215K |       82 |      |       |       |          |                              |
| 47 |                TABLE ACCESS BY LOCAL INDEX ROWID   | A                       |       1 |    5 |        93 |     +6 |  858K |       82 |      |       |       |     2.17 | Cpu (2)                      |
| 48 |                 INDEX RANGE SCAN                   | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K |      |       |       |     4.35 | Cpu (4)                      |
| 49 |              NESTED LOOPS                          |                         |       1 |    7 |        93 |     +6 |  215K |      147 |      |       |       |     1.09 | Cpu (1)                      |
| 50 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 51 |                INDEX UNIQUE SCAN                   | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 52 |               PARTITION LIST ALL                   |                         |       1 |    5 |        93 |     +6 |  215K |      147 |      |       |       |          |                              |
| 53 |                TABLE ACCESS BY LOCAL INDEX ROWID   | A                       |       1 |    5 |        93 |     +6 |  858K |      147 |      |       |       |     1.09 | Cpu (1)                      |
| 54 |                 INDEX RANGE SCAN                   | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K |      |       |       |     3.26 | Cpu (3)                      |
| 55 |              NESTED LOOPS                          |                         |       1 |    9 |         3 |    +84 |  215K |     2408 |      |       |       |          |                              |
| 56 |               NESTED LOOPS                         |                         |      23 |    9 |        93 |     +6 |  215K |     2408 |      |       |       |          |                              |
| 57 |                NESTED LOOPS                        |                         |       1 |    7 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 58 |                 TABLE ACCESS BY INDEX ROWID        | B                       |       1 |    2 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 59 |                  INDEX UNIQUE SCAN                 | UQ$B                    |       1 |    1 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 60 |                 PARTITION LIST ALL                 |                         |       1 |    5 |        93 |     +6 |  215K |     215K |      |       |       |          |                              |
| 61 |                  TABLE ACCESS BY LOCAL INDEX ROWID | A                       |       1 |    5 |        93 |     +6 |  858K |     215K |      |       |       |          |                              |
| 62 |                   INDEX RANGE SCAN                 | UQ$A                    |       1 |    4 |        93 |     +6 |  858K |     215K |      |       |       |     7.61 | Cpu (7)                      |
| 63 |                INDEX RANGE SCAN                    | I$B$ID                  |      23 |      |        95 |     +2 |  215K |     2408 | 2064 |  16MB |       |    18.48 | Cpu (4)                      |
|    |                                                    |                         |         |      |           |        |       |          |      |       |       |          | db file sequential read (13) |
| 64 |               TABLE ACCESS BY INDEX ROWID          | B                       |       1 |    2 |         3 |    +84 |  2457 |     2408 |   28 | 224KB |       |     1.09 | db file sequential read (1)  |
| 65 |       TABLE ACCESS BY INDEX ROWID                  | C                       |       1 |    2 |       186 |    +98 |  1062 |     1017 |    2 | 16384 |       |          |                              |
| 66 |        INDEX RANGE SCAN                            | UQ$C                    |       1 |    1 |       186 |    +98 |  1062 |     1017 |    3 | 24576 |       |          |                              |
| 67 |      TABLE ACCESS BY INDEX ROWID                   | C                       |       1 |    2 |       186 |    +98 |  1062 |       45 |    2 | 16384 |       |          |                              |
| 68 |       INDEX RANGE SCAN                             | UQ$C                    |       1 |    1 |       186 |    +98 |  1062 |       45 |    2 | 16384 |       |          |                              |
| 69 |    TABLE ACCESS BY INDEX ROWID                     | C                       |       1 |    2 |       186 |    +98 |  1062 |       45 |      |       |       |          |                              |
| 70 |     INDEX RANGE SCAN                               | UQ$C                    |       1 |    1 |       186 |    +98 |  1062 |       45 |      |       |       |          |                              |
==============================================================================================================================================================================================================="

and something like this (from dbms_xplan.display_awr) for the bad plan:


------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                    | Name                    | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     | Pstart| Pstop |
------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                             |                         |       |       |       |   665K(100)|          |       |       |
|   1 |  NESTED LOOPS OUTER                          |                         |     1 |   196 |       |   665K  (4)| 02:13:08 |       |       |
|   2 |   FILTER                                     |                         |       |       |       |            |          |       |       |
|   3 |    NESTED LOOPS OUTER                        |                         |     1 |   173 |       |   665K  (4)| 02:13:08 |       |       |
|   4 |     NESTED LOOPS OUTER                       |                         |  1992 |   291K|       |   661K  (4)| 02:12:20 |       |       |
|   5 |      VIEW                                    |                         |  1992 |   247K|       |   657K  (4)| 02:11:32 |       |       |
|   6 |       WINDOW SORT PUSHED RANK                |                         |  1992 |   344K|       |   657K  (4)| 02:11:32 |       |       |
|   7 |        FILTER                                |                         |       |       |       |            |          |       |       |
|   8 |         HASH GROUP BY                        |                         |  1992 |   344K|       |   657K  (4)| 02:11:32 |       |       |
|   9 |          HASH JOIN                           |                         | 39826 |  6883K|  4240K|   657K  (4)| 02:11:31 |       |       |
|  10 |           NESTED LOOPS                       |                         | 39826 |  3772K|       |  3252   (1)| 00:00:40 |       |       |
|  11 |            NESTED LOOPS                      |                         | 39826 |  3772K|       |  3252   (1)| 00:00:40 |       |       |
|  12 |             TABLE ACCESS FULL                | B                       |   186 | 10788 |       |    88   (0)| 00:00:02 |       |       |
|  13 |              SORT AGGREGATE                  |                         |     1 |    34 |       |            |          |       |       |
|  14 |               TABLE ACCESS FULL              | B                       |     1 |    34 |       |    88   (0)| 00:00:02 |       |       |
|  15 |             INLIST ITERATOR                  |                         |       |       |       |            |          |       |       |
|  16 |              INDEX RANGE SCAN                | A$TYPE                  |   214 |       |       |    12   (0)| 00:00:01 |       |       |
|  17 |            TABLE ACCESS BY GLOBAL INDEX ROWID| A                       |   214 |  8346 |       |    17   (0)| 00:00:01 | ROWID | ROWID |
|  18 |           VIEW                               |                         |    34M|  2663M|       |   501K  (5)| 01:40:23 |       |       |
|  19 |            UNION-ALL                         |                         |       |       |       |            |          |       |       |
|  20 |             HASH JOIN                        |                         |  9557K|   601M|       | 72054   (5)| 00:14:25 |       |       |
|  21 |              TABLE ACCESS FULL               | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  22 |              PARTITION LIST ALL              |                         |    31M|  1708M|       | 71806   (5)| 00:14:22 |     1 |     4 |
|  23 |               TABLE ACCESS FULL              | A                       |    31M|  1708M|       | 71806   (5)| 00:14:22 |     1 |     4 |
|  24 |             HASH JOIN                        |                         |  9553K|   601M|       | 72086   (5)| 00:14:26 |       |       |
|  25 |              TABLE ACCESS FULL               | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  26 |              PARTITION LIST ALL              |                         |    31M|  1707M|       | 71839   (5)| 00:14:23 |     1 |     4 |
|  27 |               TABLE ACCESS FULL              | A                       |    31M|  1707M|       | 71839   (5)| 00:14:23 |     1 |     4 |
|  28 |             HASH JOIN                        |                         |  5795 |   305K|       | 70853   (4)| 00:14:11 |       |       |
|  29 |              TABLE ACCESS FULL               | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  30 |              PARTITION LIST ALL              |                         |  7127 |   306K|       | 70765   (4)| 00:14:10 |     1 |     4 |
|  31 |               TABLE ACCESS FULL              | A                       |  7127 |   306K|       | 70765   (4)| 00:14:10 |     1 |     4 |
|  32 |             HASH JOIN                        |                         |  5799 |   305K|       | 70950   (4)| 00:14:12 |       |       |
|  33 |              TABLE ACCESS FULL               | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  34 |              PARTITION LIST ALL              |                         |  7149 |   307K|       | 70862   (4)| 00:14:11 |     1 |     4 |
|  35 |               TABLE ACCESS FULL              | A                       |  7149 |   307K|       | 70862   (4)| 00:14:11 |     1 |     4 |
|  36 |             HASH JOIN                        |                         |  1223K|    60M|       | 70365   (3)| 00:14:05 |       |       |
|  37 |              TABLE ACCESS FULL               | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  38 |              PARTITION LIST ALL              |                         |  4094K|   164M|       | 70257   (3)| 00:14:04 |     1 |     4 |
|  39 |               TABLE ACCESS FULL              | A                       |  4094K|   164M|       | 70257   (3)| 00:14:04 |     1 |     4 |
|  40 |             HASH JOIN                        |                         |  1147 | 71114 |       | 70464   (3)| 00:14:06 |       |       |
|  41 |              PARTITION LIST ALL              |                         |  1147 | 59644 |       | 70376   (3)| 00:14:05 |     1 |     4 |
|  42 |               TABLE ACCESS FULL              | A                       |  1147 | 59644 |       | 70376   (3)| 00:14:05 |     1 |     4 |
|  43 |              TABLE ACCESS FULL               | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  44 |             NESTED LOOPS                     |                         |    14M|  1250M|       | 75141   (7)| 00:15:02 |       |       |
|  45 |              NESTED LOOPS                    |                         |   334M|  1250M|       | 75141   (7)| 00:15:02 |       |       |
|  46 |               HASH JOIN                      |                         |    14M|   638M|       | 69494   (2)| 00:13:54 |       |       |
|  47 |                TABLE ACCESS FULL             | B                       |  4650 | 46500 |       |    88   (0)| 00:00:02 |       |       |
|  48 |                PARTITION LIST ALL            |                         |    48M|  1673M|       | 69163   (2)| 00:13:50 |     1 |     4 |
|  49 |                 TABLE ACCESS FULL            | A                       |    48M|  1673M|       | 69163   (2)| 00:13:50 |     1 |     4 |
|  50 |               INDEX RANGE SCAN               | D                       |    23 |       |       |     0   (0)|          |       |       |
|  51 |              TABLE ACCESS BY INDEX ROWID     | I$D$ID                  |     1 |    44 |       |     2   (0)| 00:00:01 |       |       |
|  52 |      TABLE ACCESS BY INDEX ROWID             | C                       |     1 |    23 |       |     2   (0)| 00:00:01 |       |       |
|  53 |       INDEX RANGE SCAN                       | UQ$C                    |     1 |       |       |     1   (0)| 00:00:01 |       |       |
|  54 |     TABLE ACCESS BY INDEX ROWID              | C                       |     1 |    23 |       |     2   (0)| 00:00:01 |       |       |
|  55 |      INDEX RANGE SCAN                        | UQ$C                    |     1 |       |       |     1   (0)| 00:00:01 |       |       |
|  56 |   TABLE ACCESS BY INDEX ROWID                | C                       |     1 |    23 |       |     2   (0)| 00:00:01 |       |       |
|  57 |    INDEX RANGE SCAN                          | UQ$C                    |     1 |       |       |     1   (0)| 00:00:01 |       |       |
------------------------------------------------------------------------------------------------------------------------------------------------

Note
-----
- cardinality feedback used for this statement

?

If your initial response is “damn cardinality feedback once again is replacing a great plan with a horrible one, what should I do to stop it from doing that?”, and you start acting on it without pausing for deeper analysis, then you’re making the same mistake I almost made here.

Actually, I was torn between blaming cardinality feedback or some weird optimizer bug preventing predicate pushdown (or a combination of both) for ruining the good plan. In any case, it all seemed perfectly clear: the good plan completed within a couple of minutes, while the bad one never returned (as I was told), the good plan had much lower cost, the bad plan fails to push the predicate down inside a UNION ALL block, the bad plan is a bunch of full tablescans. So regardless of the specific mechanism, something is causing the optimizer to make an absurd choice here.  Or is it?..

Let’s add some information: as it turned out, “the bad plan never returned” meant that the user gave up after 5 minutes or so. I ran the query with a bad plan (using the outline extracted with dbms_xplan.display_awr to force it) and saw it complete within 12 minutes (after completing some 50+ GB of physical reads). Not great, but not as horrible as I initially imagined… But still, 12 minutes compared to 3! And 50+ GB of physical reads vs just 75 MB in the good plan! So it doesn’t change anything in our analysis?..

Actually it does… if we do the math — 50 GB in 12 minute means about 70 MB/s I/O transfer speed… that doesn’t look great at all — that’s less than a cheap commodity HDD is capable of… And actually I just happened to know (from benchmarks) that this storage array was capable of delivering 300-400 MB/s serial sequential read performance (and 3-4 GB/s in parallel). So this is the first indication that our original theory might not be correct…

With this in mind, let’s take another look at the “good” plan, in particular, at the global stats on the top of the SQL real-time monitoring report. Whoa! 20M logical reads! This means that the buffer cache hit ratio was 99.95% for this query! Is it sensible for the optimizer to expect this much help from the cache? By default, it’s not expecting any, but as it happened, optimizer_index_caching on that particular database system was set to 80. Still, there is a huge difference between 80 and 99.95%, more than it may seem at the first sight: it means that the amount of physical reads would be off by a factor of 400!

So now it seems like the good plan is not that good after all. Yes, when we get lucky with cache, the execution time is going to be decent, but put a little pressure on the buffer cache, the hit ratio drops and nothing is left of good performance.

But that’s not all. If we look closer on the plan, we’ll see that the UNION ALL operation combines together results of 6 similar looking HASH JOINs of the same pair of tables. This reflects the structure of one of the views in that query:


select expr1

from A, B

where A.id = B.id

and <condition1>

UNION ALL

select expr2

from A, B

where A.id = B.id

and <condition2>

...

which can easily be rewritten as:


select case when <condition1> then expr1 when <condition2> then expr2 ... end

from A, B

where A.id = B.id

and (<condition1> or <condition2>...)

So let’s put it all together: the original picture where the stupid optimizer suppressed a perfectly good plan in favor of a much worse one completely disappears. Instead we see an entirely different picture: a poorly written query happens to have an okay performance thanks to low pressure on the buffer cache. The optimizer makes a perfectly sensible choice in favor of an actually better plan which unfortunately doesn’t deliver same performance because an I/O issue is crippling sequential read performance! Instead of stabilizing the original plan, our focus should be on rewriting the query and restoring the I/O performance!

As this example shows,  it really pays not to jump to conclusion and to always cover all bases when analyzing performance issues. In particular, when dealing with plan regressions, it helps to:

  1. consider how good/bad the original plan actually was
  2. estimate the role played by buffer cache
  3. see if multi- and single-block read timings are in the right ballpark in both cases
  4. try and use numbers instead of adjectives for describing performance (e.g. not “horrible”, but “12 minutes 26 seconds to fetch all rows”).

And the opposite list, things that should be avoided:

  1. don’t assume a plan is bad just because it contains a bunch of full table scans (after all these years, I still sometimes subconsciously do that!)
  2. don’t assume a plan is bad just because the optimizer won’t push down the predicate inside a view — it could be a reasonable cost-based decision (I have some personal history with predicate pushdowns, so maybe this one is just for me!)
  3. always put statement execution time into the right context.

P.S. Thanks a lot to sir Jonathan Lewis, whose input on twitter helped me to see the issue in the correct light!

P.S. Merry Christmas to everyone who sticks to Julian’s calendar!

 

 

5 thoughts on “Covering bases

  1. Hi savvinov,Planning to partition a big table FND_LOBS , can you please suggest best and fastest method to do the same. it is of 580gb size. ThanksVenkat

  2. Hi Nikolay,

    Before asking for a clarification, and since this is the first time I’m posting a comment on your blog, I’d like to let you know that your blog posts are very educative and interesting, so even though you mentioned in the “Relocation” blog post that you didn’t receive enough feedback to keep you motivated to continue the SQL performance series, I’d certainly be glad to read your posts about solving performance problems you encounter.

    Having said that, I have a question regarding the two execution plans you analyzed. You mentioned that “Instead of stabilizing the original plan, our focus should be on rewriting the query and restoring the I/O performance!”. Suppose we can’t rewrite the SQL, but the I/O performance is not degraded any more. Is it possible to infer that in that case, the second plan would give a better response time than the first one?

    If we compare both queries by number of LIOs (I’m not taking into account other factors which could influence the PIO and LIO read time which you analyzed here: https://savvinov.com/2015/02/17/logical-io/):
    – first one performs 20M buffer gets (= approx. 153 GB of scanned buffers, 95.95% of them were in the buffer cache)
    – second one performs 6.5M buffer gets (50 GB of scanned buffers, almost all of them are probably turned into physical I/Os, even more so if they are performed as direct path reads).
    If the second query performs 50GB of physical IOs and the storage system has a throughput of 3GB/s, that means the data can be scanned in 17 seconds, and it seems obvious that the second query would be faster and more efficient, and probably also much less CPU consuming given the fact that it performs 3 times less LIOs, even though they turn into PIOs. So it seems we should stick to this execution plan.

    However, I’m interested in your opinion about how would you approach this problem, again, assuming you can’t rewrite the SQL, if the storage slowdowns appeared sporadically, e.g. because of parallel backup jobs which are out of your control? The first priority would be to fix the storage problems, but how would you proceed in the meantime? Would you use a baseline to always force one of the presented two execution plans, presumably the second one, even though in case of storage slowdowns the first one would have a better response time at the expense of extra burned CPU and assuming the relevant data is present in the buffer cache most of the time? The answer to that question probably also heavily depends on other factors such as database workload patterns, e.g. the time of day the query is running, does it affect other users’ response time, etc….and what seems problematic here is that neither of the two execution plans provides stability – the first one is heavily dependent on buffered data, the second one is heavily dependent on storage IO performance.

    Thank you and regards,
    Jure Bratina

    1. Hi Jure,

      first of all, thank you for the feedback and the question. It’s really gratifying to know that I have readers who reader my posts thoroughly and do even their own analysis of the cases I describe!

      Now to your question. If rewriting the SQL is not possible, and there is no immediate solution for the I/O problem, then the optimal course of action would depend on many factors, such as:

      1) how frequently does the query run?
      2) how exactly is it running — i.e. manually from, say, a SQL Developer window, or from an application that uses a connection pool?
      3) is it always running at the same time? how much variation in global database I/O volume during that time window can we expect?
      4) is the query text likely to change over time?
      5) is the database I/O or CPU bound?
      6) is the I/O problem affecting serial and sequential reads equally?

      Under some circumstances what I originally intended to do (stabilize the “good” plan) would still be reasonable.

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 )

Connecting to %s