Tuesday, February 13, 2018

SQL Magic Squares - or Why the Optimizer does not like Magic

A long-time player at the Oracle Dev Gym tried his hand at generating Magic Squares using SQL.



When he attempted to tune his statement a bit, he was surprised that it didn't go a little faster as expected, rather it went from 2 minutes to 45 minutes? At that point he contacted me to see if I could explain the mystery...



So thank you, Hamid Talebian, for the interesting case. It was fun to play around with that SQL, and here's the findings...

(Note this post is not about best ways to generate Magic Squares - this is just about how the optimizer has a hard time trying to do Magic ;-)

First I'll show you the original SQL by Hamid:

select count(*) from (
with dat as (
   select level n from dual connect by rownum <=16
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8
     , d9.n n9, da.n na, db.n nb, dc.n nc, dd.n nd, de.n ne, df.n nf, dg.n ng
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8
     , dat d9, dat da, dat db, dat dc, dat dd, dat de, dat df, dat dg
 where not (
            d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d5.n in (d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d6.n in (d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d7.n in (d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d8.n in (d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d9.n in (da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or da.n in (db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or db.n in (dc.n, dd.n, de.n, df.n, dg.n)
         or dc.n in (dd.n, de.n, df.n, dg.n)
         or dd.n in (de.n, df.n, dg.n)
         or de.n in (df.n, dg.n)
         or df.n = dg.n
       )
   and d1.n + d2.n + d3.n + d4.n = 34
   and d5.n + d6.n + d7.n + d8.n = 34
   and d9.n + da.n + db.n + dc.n = 34
   and dd.n + de.n + df.n + dg.n = 34
   and d1.n + d5.n + d9.n + dd.n = 34
   and d2.n + d6.n + da.n + de.n = 34
   and d3.n + d7.n + db.n + df.n = 34
   and d4.n + d8.n + dc.n + dg.n = 34
   and d1.n + d6.n + db.n + dg.n = 34
   and d4.n + d7.n + da.n + dd.n = 34
);

He executed this in 2 minutes (my environment 1.5 minute) and it output a count of 7.040 as expected.

But could it be improved? Could the number of comparisons executed be reduced a bit? Well sure, the way the sums of all verticals, horizontals and diagonals all must be equal to 34, Hamid could for example skip the predicate that tests if the bottom horizontal line is 34 - if all the others are true, then this must also be true.

So comment out that line and see if it isn't a little faster since it needs to evaluate less, right?

select count(*) from (
with dat as (
   select level n from dual connect by rownum <=16
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8
     , d9.n n9, da.n na, db.n nb, dc.n nc, dd.n nd, de.n ne, df.n nf, dg.n ng
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8
     , dat d9, dat da, dat db, dat dc, dat dd, dat de, dat df, dat dg
 where not (
            d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d5.n in (d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d6.n in (d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d7.n in (d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d8.n in (d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d9.n in (da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or da.n in (db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or db.n in (dc.n, dd.n, de.n, df.n, dg.n)
         or dc.n in (dd.n, de.n, df.n, dg.n)
         or dd.n in (de.n, df.n, dg.n)
         or de.n in (df.n, dg.n)
         or df.n = dg.n
       )
   and d1.n + d2.n + d3.n + d4.n = 34
   and d5.n + d6.n + d7.n + d8.n = 34
   and d9.n + da.n + db.n + dc.n = 34
--   and dd.n + de.n + df.n + dg.n = 34 -- by logic of magic square this is not needed
   and d1.n + d5.n + d9.n + dd.n = 34
   and d2.n + d6.n + da.n + de.n = 34
   and d3.n + d7.n + db.n + df.n = 34
   and d4.n + d8.n + dc.n + dg.n = 34
   and d1.n + d6.n + db.n + dg.n = 34
   and d4.n + d7.n + da.n + dd.n = 34
);

This gave the same result as expected, but executed in 45 minutes (my environment 37 minutes) - more than 20 times slower, not faster!

What happened? Well, I'll try with a 3x3 Magic Square to look a little closer:

with dat as (
   select level n from dual connect by rownum <=9
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8, d9.n n9
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8, dat d9
 where not (
             d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n)
          or d5.n in (d6.n, d7.n, d8.n, d9.n)
          or d6.n in (d7.n, d8.n, d9.n)
          or d7.n in (d8.n, d9.n)
          or d8.n in (d9.n)
       )
   and d1.n + d2.n + d3.n = 15
   and d4.n + d5.n + d6.n = 15
   and d7.n + d8.n + d9.n = 15
   and d1.n + d4.n + d7.n = 15
   and d2.n + d5.n + d8.n = 15
   and d3.n + d6.n + d9.n = 15
   and d1.n + d5.n + d9.n = 15
   and d3.n + d5.n + d7.n = 15
;

It executes in less than 1/100th of a second returning this expected result (all 8 rows are actually rotations or reflections of the one single 3x3 magic square that exists):

        N1         N2         N3         N4         N5         N6         N7         N8         N9
---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
         8          3          4          1          5          9          6          7          2
         8          1          6          3          5          7          4          9          2
         6          7          2          1          5          9          8          3          4
         6          1          8          7          5          3          2          9          4
         4          9          2          3          5          7          8          1          6
         4          3          8          9          5          1          2          7          6
         2          9          4          7          5          3          6          1          8
         2          7          6          9          5          1          4          3          8

 8 rows selected 

And have a look at the plan generated from the execution:

-----------------------------------------------------------------------------------------------------------------------------------------------------------         
| Id  | Operation                                | Name                      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
|   0 | SELECT STATEMENT                         |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   1 |  TEMP TABLE TRANSFORMATION               |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   2 |   LOAD AS SELECT (CURSOR DURATION MEMORY)| SYS_TEMP_0FD9D680F_35DEEB |      1 |        |      0 |00:00:00.01 |       1 |  1024 |  1024 |          |         
|   3 |    COUNT                                 |                           |      1 |        |      9 |00:00:00.01 |       0 |       |       |          |         
|   4 |     CONNECT BY WITHOUT FILTERING         |                           |      1 |        |      9 |00:00:00.01 |       0 |  2048 |  2048 | 2048  (0)|         
|   5 |      FAST DUAL                           |                           |      1 |      1 |      1 |00:00:00.01 |       0 |       |       |          |         
|   6 |   NESTED LOOPS                           |                           |      1 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|   7 |    NESTED LOOPS                          |                           |      1 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|   8 |     NESTED LOOPS                         |                           |      1 |      1 |     56 |00:00:00.01 |       0 |       |       |          |         
|   9 |      NESTED LOOPS                        |                           |      1 |      1 |     96 |00:00:00.01 |       0 |       |       |          |         
|  10 |       NESTED LOOPS                       |                           |      1 |      1 |    176 |00:00:00.01 |       0 |       |       |          |         
|  11 |        NESTED LOOPS                      |                           |      1 |      1 |    288 |00:00:00.01 |       0 |       |       |          |         
|  12 |         NESTED LOOPS                     |                           |      1 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|  13 |          NESTED LOOPS                    |                           |      1 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
|  14 |           VIEW                           |                           |      1 |      1 |      9 |00:00:00.01 |       0 |       |       |          |         
|  15 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D680F_35DEEB |      1 |      1 |      9 |00:00:00.01 |       0 |       |       |          |         
|* 16 |           VIEW                           |                           |      9 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
|  17 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D680F_35DEEB |      9 |      1 |     81 |00:00:00.01 |       0 |       |       |          |         
|* 18 |          VIEW                            |                           |     72 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|  19 |           TABLE ACCESS FULL              | SYS_TEMP_0FD9D680F_35DEEB |     72 |      1 |    648 |00:00:00.01 |       0 |       |       |          |         
|* 20 |         VIEW                             |                           |     48 |      1 |    288 |00:00:00.01 |       0 |       |       |          |         
|  21 |          TABLE ACCESS FULL               | SYS_TEMP_0FD9D680F_35DEEB |     48 |      1 |    432 |00:00:00.01 |       0 |       |       |          |         
|* 22 |        VIEW                              |                           |    288 |      1 |    176 |00:00:00.01 |       0 |       |       |          |         
|  23 |         TABLE ACCESS FULL                | SYS_TEMP_0FD9D680F_35DEEB |    288 |      1 |   2592 |00:00:00.01 |       0 |       |       |          |         
|* 24 |       VIEW                               |                           |    176 |      1 |     96 |00:00:00.01 |       0 |       |       |          |         
|  25 |        TABLE ACCESS FULL                 | SYS_TEMP_0FD9D680F_35DEEB |    176 |      1 |   1584 |00:00:00.01 |       0 |       |       |          |         
|* 26 |      VIEW                                |                           |     96 |      1 |     56 |00:00:00.01 |       0 |       |       |          |         
|  27 |       TABLE ACCESS FULL                  | SYS_TEMP_0FD9D680F_35DEEB |     96 |      1 |    864 |00:00:00.01 |       0 |       |       |          |         
|* 28 |     VIEW                                 |                           |     56 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|  29 |      TABLE ACCESS FULL                   | SYS_TEMP_0FD9D680F_35DEEB |     56 |      1 |    504 |00:00:00.01 |       0 |       |       |          |         
|* 30 |    VIEW                                  |                           |      8 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|  31 |     TABLE ACCESS FULL                    | SYS_TEMP_0FD9D680F_35DEEB |      8 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
                                                                                                                                                                    
Predicate Information (identified by operation id):                                                                                                                 
---------------------------------------------------                                                                                                                 
                                                                                                                                                                    
  16 - filter("D8"."N"<>"D9"."N")                                                                                                                                   
  18 - filter(("D7"."N"<>"D8"."N" AND "D7"."N"<>"D9"."N" AND "D7"."N"+"D8"."N"+"D9"."N"=15))                                                                        
  20 - filter(("D6"."N"<>"D7"."N" AND "D6"."N"<>"D8"."N" AND "D6"."N"<>"D9"."N"))                                                                                   
  22 - filter(("D3"."N"<>"D6"."N" AND "D3"."N"<>"D7"."N" AND "D3"."N"<>"D8"."N" AND "D3"."N"<>"D9"."N" AND "D3"."N"+"D6"."N"+"D9"."N"=15))                          
  24 - filter(("D3"."N"<>"D5"."N" AND "D5"."N"<>"D6"."N" AND "D5"."N"<>"D7"."N" AND "D5"."N"<>"D8"."N" AND "D5"."N"<>"D9"."N" AND                                   
              "D3"."N"+"D5"."N"+"D7"."N"=15))                                                                                                                       
  26 - filter(("D3"."N"<>"D4"."N" AND "D4"."N"<>"D5"."N" AND "D4"."N"<>"D6"."N" AND "D4"."N"<>"D7"."N" AND "D4"."N"<>"D8"."N" AND                                   
              "D4"."N"<>"D9"."N" AND "D4"."N"+"D5"."N"+"D6"."N"=15))                                                                                                
  28 - filter(("D1"."N"<>"D3"."N" AND "D1"."N"<>"D4"."N" AND "D1"."N"<>"D5"."N" AND "D1"."N"<>"D6"."N" AND "D1"."N"<>"D7"."N" AND                                   
              "D1"."N"<>"D8"."N" AND "D1"."N"<>"D9"."N" AND "D1"."N"+"D4"."N"+"D7"."N"=15 AND "D1"."N"+"D5"."N"+"D9"."N"=15))                                       
  30 - filter(("D1"."N"<>"D2"."N" AND "D2"."N"<>"D3"."N" AND "D2"."N"<>"D4"."N" AND "D2"."N"<>"D5"."N" AND "D2"."N"<>"D6"."N" AND                                   
              "D2"."N"<>"D7"."N" AND "D2"."N"<>"D8"."N" AND "D2"."N"<>"D9"."N" AND "D1"."N"+"D2"."N"+"D3"."N"=15 AND "D2"."N"+"D5"."N"+"D8"."N"=15))                

From the predicates I can deduce that step 15 is table alias D9, step 17 is D8, and so on. (I think there's a way to make column "Name" contain the table alias, but I forget how.)

Then I repeat the exercise of commenting out a "superfluous" predicate:

with dat as (
   select level n from dual connect by rownum <=9
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8, d9.n n9
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8, dat d9
 where not (
             d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n)
          or d5.n in (d6.n, d7.n, d8.n, d9.n)
          or d6.n in (d7.n, d8.n, d9.n)
          or d7.n in (d8.n, d9.n)
          or d8.n in (d9.n)
       )
   and d1.n + d2.n + d3.n = 15
   and d4.n + d5.n + d6.n = 15
--   and d7.n + d8.n + d9.n = 15 -- by logic of magic square this is not needed
   and d1.n + d4.n + d7.n = 15
   and d2.n + d5.n + d8.n = 15
   and d3.n + d6.n + d9.n = 15
   and d1.n + d5.n + d9.n = 15
   and d3.n + d5.n + d7.n = 15
;

I get the same result, but in about 2/100ths of a second. The plan now looks like this:

-----------------------------------------------------------------------------------------------------------------------------------------------------------         
| Id  | Operation                                | Name                      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
|   0 | SELECT STATEMENT                         |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   1 |  TEMP TABLE TRANSFORMATION               |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   2 |   LOAD AS SELECT (CURSOR DURATION MEMORY)| SYS_TEMP_0FD9D6810_35DEEB |      1 |        |      0 |00:00:00.01 |       1 |  1024 |  1024 |          |         
|   3 |    COUNT                                 |                           |      1 |        |      9 |00:00:00.01 |       0 |       |       |          |         
|   4 |     CONNECT BY WITHOUT FILTERING         |                           |      1 |        |      9 |00:00:00.01 |       0 |  2048 |  2048 | 2048  (0)|         
|   5 |      FAST DUAL                           |                           |      1 |      1 |      1 |00:00:00.01 |       0 |       |       |          |         
|   6 |   NESTED LOOPS                           |                           |      1 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|   7 |    NESTED LOOPS                          |                           |      1 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|   8 |     NESTED LOOPS                         |                           |      1 |      1 |    288 |00:00:00.02 |       0 |       |       |          |         
|   9 |      NESTED LOOPS                        |                           |      1 |      1 |    704 |00:00:00.02 |       0 |       |       |          |         
|  10 |       NESTED LOOPS                       |                           |      1 |      1 |   1440 |00:00:00.02 |       0 |       |       |          |         
|  11 |        NESTED LOOPS                      |                           |      1 |      1 |   3024 |00:00:00.01 |       0 |       |       |          |         
|  12 |         NESTED LOOPS                     |                           |      1 |      1 |    504 |00:00:00.01 |       0 |       |       |          |         
|  13 |          NESTED LOOPS                    |                           |      1 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
|  14 |           VIEW                           |                           |      1 |      1 |      9 |00:00:00.01 |       0 |       |       |          |         
|  15 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D6810_35DEEB |      1 |      1 |      9 |00:00:00.01 |       0 |       |       |          |         
|* 16 |           VIEW                           |                           |      9 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
|  17 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D6810_35DEEB |      9 |      1 |     81 |00:00:00.01 |       0 |       |       |          |         
|* 18 |          VIEW                            |                           |     72 |      1 |    504 |00:00:00.01 |       0 |       |       |          |         
|  19 |           TABLE ACCESS FULL              | SYS_TEMP_0FD9D6810_35DEEB |     72 |      1 |    648 |00:00:00.01 |       0 |       |       |          |         
|* 20 |         VIEW                             |                           |    504 |      1 |   3024 |00:00:00.01 |       0 |       |       |          |         
|  21 |          TABLE ACCESS FULL               | SYS_TEMP_0FD9D6810_35DEEB |    504 |      1 |   4536 |00:00:00.01 |       0 |       |       |          |         
|* 22 |        VIEW                              |                           |   3024 |      1 |   1440 |00:00:00.01 |       0 |       |       |          |         
|  23 |         TABLE ACCESS FULL                | SYS_TEMP_0FD9D6810_35DEEB |   3024 |      1 |  27216 |00:00:00.01 |       0 |       |       |          |         
|* 24 |       VIEW                               |                           |   1440 |      1 |    704 |00:00:00.01 |       0 |       |       |          |         
|  25 |        TABLE ACCESS FULL                 | SYS_TEMP_0FD9D6810_35DEEB |   1440 |      1 |  12960 |00:00:00.01 |       0 |       |       |          |         
|* 26 |      VIEW                                |                           |    704 |      1 |    288 |00:00:00.01 |       0 |       |       |          |         
|  27 |       TABLE ACCESS FULL                  | SYS_TEMP_0FD9D6810_35DEEB |    704 |      1 |   6336 |00:00:00.01 |       0 |       |       |          |         
|* 28 |     VIEW                                 |                           |    288 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|  29 |      TABLE ACCESS FULL                   | SYS_TEMP_0FD9D6810_35DEEB |    288 |      1 |   2592 |00:00:00.01 |       0 |       |       |          |         
|* 30 |    VIEW                                  |                           |     48 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|  31 |     TABLE ACCESS FULL                    | SYS_TEMP_0FD9D6810_35DEEB |     48 |      1 |    432 |00:00:00.01 |       0 |       |       |          |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
                                                                                                                                                                    
Predicate Information (identified by operation id):                                                                                                                 
---------------------------------------------------                                                                                                                 
                                                                                                                                                                    
  16 - filter("D8"."N"<>"D9"."N")                                                                                                                                   
  18 - filter(("D7"."N"<>"D8"."N" AND "D7"."N"<>"D9"."N"))                                                                                                          
  20 - filter(("D6"."N"<>"D7"."N" AND "D6"."N"<>"D8"."N" AND "D6"."N"<>"D9"."N"))                                                                                   
  22 - filter(("D3"."N"<>"D6"."N" AND "D3"."N"<>"D7"."N" AND "D3"."N"<>"D8"."N" AND "D3"."N"<>"D9"."N" AND "D3"."N"+"D6"."N"+"D9"."N"=15))                          
  24 - filter(("D3"."N"<>"D5"."N" AND "D5"."N"<>"D6"."N" AND "D5"."N"<>"D7"."N" AND "D5"."N"<>"D8"."N" AND "D5"."N"<>"D9"."N" AND                                   
              "D3"."N"+"D5"."N"+"D7"."N"=15))                                                                                                                       
  26 - filter(("D3"."N"<>"D4"."N" AND "D4"."N"<>"D5"."N" AND "D4"."N"<>"D6"."N" AND "D4"."N"<>"D7"."N" AND "D4"."N"<>"D8"."N" AND                                   
              "D4"."N"<>"D9"."N" AND "D4"."N"+"D5"."N"+"D6"."N"=15))                                                                                                
  28 - filter(("D1"."N"<>"D3"."N" AND "D1"."N"<>"D4"."N" AND "D1"."N"<>"D5"."N" AND "D1"."N"<>"D6"."N" AND "D1"."N"<>"D7"."N" AND                                   
              "D1"."N"<>"D8"."N" AND "D1"."N"<>"D9"."N" AND "D1"."N"+"D4"."N"+"D7"."N"=15 AND "D1"."N"+"D5"."N"+"D9"."N"=15))                                       
  30 - filter(("D1"."N"<>"D2"."N" AND "D2"."N"<>"D3"."N" AND "D2"."N"<>"D4"."N" AND "D2"."N"<>"D5"."N" AND "D2"."N"<>"D6"."N" AND                                   
              "D2"."N"<>"D7"."N" AND "D2"."N"<>"D8"."N" AND "D2"."N"<>"D9"."N" AND "D1"."N"+"D2"."N"+"D3"."N"=15 AND "D2"."N"+"D5"."N"+"D8"."N"=15))                

The plan is practically identical, but notice the predicate information for step 18. In the first plan it was:

  18 - filter(("D7"."N"<>"D8"."N" AND "D7"."N"<>"D9"."N" AND "D7"."N"+"D8"."N"+"D9"."N"=15))                                                                        

In the second it is:

  18 - filter(("D7"."N"<>"D8"."N" AND "D7"."N"<>"D9"."N"))                                                                                                          

So it is at this point that my "saving" is removed from the filter predicate. Which means that the database works a tiny bit less since there is one less comparison to evaluate.

But the effect of the removal of this part of filter predicate 18 is, that the A-Rows column of step 18 increases from originally 48 to now 504! Which cascades down through the "nested loops tree" so step 23 has to process 27.216 rows instead of originally 2.592.

The "extra" rows processed are filtered away in the end, since the other predicates after step 23 reduce the number of rows, but the damage has been done. A lot more rows have been generated wastefully, just to be thrown away again later.

Now here's a specially quirky thing about this case. Have you always been told that the order of the tables in the FROM clause does not matter? Well, in this case it does make a difference - I'll try reversing the order of tables in the FROM clause:

with dat as (
   select level n from dual connect by rownum <=9
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8, d9.n n9
  from dat d9, dat d8, dat d7, dat d6, dat d5, dat d4, dat d3, dat d2, dat d1
 where not (
             d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n)
          or d5.n in (d6.n, d7.n, d8.n, d9.n)
          or d6.n in (d7.n, d8.n, d9.n)
          or d7.n in (d8.n, d9.n)
          or d8.n in (d9.n)
       )
   and d1.n + d2.n + d3.n = 15
   and d4.n + d5.n + d6.n = 15
--   and d7.n + d8.n + d9.n = 15 -- by logic of magic square this is not needed
   and d1.n + d4.n + d7.n = 15
   and d2.n + d5.n + d8.n = 15
   and d3.n + d6.n + d9.n = 15
   and d1.n + d5.n + d9.n = 15
   and d3.n + d5.n + d7.n = 15
;

This goes fast again and the plan looks like this:

-----------------------------------------------------------------------------------------------------------------------------------------------------------         
| Id  | Operation                                | Name                      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
|   0 | SELECT STATEMENT                         |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   1 |  TEMP TABLE TRANSFORMATION               |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   2 |   LOAD AS SELECT (CURSOR DURATION MEMORY)| SYS_TEMP_0FD9D6812_35DEEB |      1 |        |      0 |00:00:00.01 |       1 |  1024 |  1024 |          |         
|   3 |    COUNT                                 |                           |      1 |        |      9 |00:00:00.01 |       0 |       |       |          |         
|   4 |     CONNECT BY WITHOUT FILTERING         |                           |      1 |        |      9 |00:00:00.01 |       0 |  2048 |  2048 | 2048  (0)|         
|   5 |      FAST DUAL                           |                           |      1 |      1 |      1 |00:00:00.01 |       0 |       |       |          |         
|   6 |   NESTED LOOPS                           |                           |      1 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|   7 |    NESTED LOOPS                          |                           |      1 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|   8 |     NESTED LOOPS                         |                           |      1 |      1 |     56 |00:00:00.01 |       0 |       |       |          |         
|   9 |      NESTED LOOPS                        |                           |      1 |      1 |     96 |00:00:00.01 |       0 |       |       |          |         
|  10 |       NESTED LOOPS                       |                           |      1 |      1 |    176 |00:00:00.01 |       0 |       |       |          |         
|  11 |        NESTED LOOPS                      |                           |      1 |      1 |    288 |00:00:00.01 |       0 |       |       |          |         
|  12 |         NESTED LOOPS                     |                           |      1 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|  13 |          NESTED LOOPS                    |                           |      1 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
|  14 |           VIEW                           |                           |      1 |      1 |      9 |00:00:00.01 |       0 |       |       |          |         
|  15 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D6812_35DEEB |      1 |      1 |      9 |00:00:00.01 |       0 |       |       |          |         
|* 16 |           VIEW                           |                           |      9 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
|  17 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D6812_35DEEB |      9 |      1 |     81 |00:00:00.01 |       0 |       |       |          |         
|* 18 |          VIEW                            |                           |     72 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|  19 |           TABLE ACCESS FULL              | SYS_TEMP_0FD9D6812_35DEEB |     72 |      1 |    648 |00:00:00.01 |       0 |       |       |          |         
|* 20 |         VIEW                             |                           |     48 |      1 |    288 |00:00:00.01 |       0 |       |       |          |         
|  21 |          TABLE ACCESS FULL               | SYS_TEMP_0FD9D6812_35DEEB |     48 |      1 |    432 |00:00:00.01 |       0 |       |       |          |         
|* 22 |        VIEW                              |                           |    288 |      1 |    176 |00:00:00.01 |       0 |       |       |          |         
|  23 |         TABLE ACCESS FULL                | SYS_TEMP_0FD9D6812_35DEEB |    288 |      1 |   2592 |00:00:00.01 |       0 |       |       |          |         
|* 24 |       VIEW                               |                           |    176 |      1 |     96 |00:00:00.01 |       0 |       |       |          |         
|  25 |        TABLE ACCESS FULL                 | SYS_TEMP_0FD9D6812_35DEEB |    176 |      1 |   1584 |00:00:00.01 |       0 |       |       |          |         
|* 26 |      VIEW                                |                           |     96 |      1 |     56 |00:00:00.01 |       0 |       |       |          |         
|  27 |       TABLE ACCESS FULL                  | SYS_TEMP_0FD9D6812_35DEEB |     96 |      1 |    864 |00:00:00.01 |       0 |       |       |          |         
|* 28 |     VIEW                                 |                           |     56 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|  29 |      TABLE ACCESS FULL                   | SYS_TEMP_0FD9D6812_35DEEB |     56 |      1 |    504 |00:00:00.01 |       0 |       |       |          |         
|* 30 |    VIEW                                  |                           |      8 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|  31 |     TABLE ACCESS FULL                    | SYS_TEMP_0FD9D6812_35DEEB |      8 |      1 |     72 |00:00:00.01 |       0 |       |       |          |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
                                                                                                                                                                    
Predicate Information (identified by operation id):                                                                                                                 
---------------------------------------------------                                                                                                                 
                                                                                                                                                                    
  16 - filter("D1"."N"<>"D2"."N")                                                                                                                                   
  18 - filter(("D1"."N"<>"D3"."N" AND "D2"."N"<>"D3"."N" AND "D1"."N"+"D2"."N"+"D3"."N"=15))                                                                        
  20 - filter(("D1"."N"<>"D4"."N" AND "D2"."N"<>"D4"."N" AND "D3"."N"<>"D4"."N"))                                                                                   
  22 - filter(("D1"."N"<>"D7"."N" AND "D2"."N"<>"D7"."N" AND "D3"."N"<>"D7"."N" AND "D4"."N"<>"D7"."N" AND "D1"."N"+"D4"."N"+"D7"."N"=15))                          
  24 - filter(("D1"."N"<>"D5"."N" AND "D2"."N"<>"D5"."N" AND "D3"."N"<>"D5"."N" AND "D4"."N"<>"D5"."N" AND "D5"."N"<>"D7"."N" AND                                   
              "D3"."N"+"D5"."N"+"D7"."N"=15))                                                                                                                       
  26 - filter(("D1"."N"<>"D6"."N" AND "D2"."N"<>"D6"."N" AND "D3"."N"<>"D6"."N" AND "D4"."N"<>"D6"."N" AND "D5"."N"<>"D6"."N" AND                                   
              "D6"."N"<>"D7"."N" AND "D4"."N"+"D5"."N"+"D6"."N"=15))                                                                                                
  28 - filter(("D1"."N"<>"D9"."N" AND "D2"."N"<>"D9"."N" AND "D3"."N"<>"D9"."N" AND "D4"."N"<>"D9"."N" AND "D5"."N"<>"D9"."N" AND                                   
              "D6"."N"<>"D9"."N" AND "D7"."N"<>"D9"."N" AND "D3"."N"+"D6"."N"+"D9"."N"=15 AND "D1"."N"+"D5"."N"+"D9"."N"=15))                                       
  30 - filter(("D1"."N"<>"D8"."N" AND "D2"."N"<>"D8"."N" AND "D3"."N"<>"D8"."N" AND "D4"."N"<>"D8"."N" AND "D5"."N"<>"D8"."N" AND                                   
              "D6"."N"<>"D8"."N" AND "D7"."N"<>"D8"."N" AND "D8"."N"<>"D9"."N" AND "D2"."N"+"D5"."N"+"D8"."N"=15))                                                  

This time I see from the predicates that it starts with table D1, then D2, and so on. This means that since I've left out the predicate that uses D7+D8+D9, it does not affect the earlier steps of the access plan - they are still good filtering away rows as soon as possible.

In fact if I had left the predicate in place, it would have been part of the filter in step 30, and at this point the needed rows have already been filtered and the extra predicate would have made no difference at all.

So does the optimizer always access the tables in the reverse order of the FROM clause? Maybe in some very early versions of the database - I don't know - but definitely not now. One problem in this case is that it has nothing specific to decide which order is the best - as far as it believes (column E-Rows) all steps return a single row.

That I can improve upon - let the optimizer know a better cardinality:

with dat as (
   select /*+ cardinality(9) */ level n from dual connect by rownum <=9
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8, d9.n n9
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8, dat d9
 where not (
             d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n)
          or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n)
          or d5.n in (d6.n, d7.n, d8.n, d9.n)
          or d6.n in (d7.n, d8.n, d9.n)
          or d7.n in (d8.n, d9.n)
          or d8.n in (d9.n)
       )
   and d1.n + d2.n + d3.n = 15
   and d4.n + d5.n + d6.n = 15
--   and d7.n + d8.n + d9.n = 15 -- by logic of magic square this is not needed
   and d1.n + d4.n + d7.n = 15
   and d2.n + d5.n + d8.n = 15
   and d3.n + d6.n + d9.n = 15
   and d1.n + d5.n + d9.n = 15
   and d3.n + d5.n + d7.n = 15
;

Again it goes fast, even though the order in the FROM clause is the same as when I got the "bad" plan. So what's the plan now look like?

-----------------------------------------------------------------------------------------------------------------------------------------------------------         
| Id  | Operation                                | Name                      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |  OMem |  1Mem | Used-Mem |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
|   0 | SELECT STATEMENT                         |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   1 |  TEMP TABLE TRANSFORMATION               |                           |      1 |        |      8 |00:00:00.01 |       2 |       |       |          |         
|   2 |   LOAD AS SELECT (CURSOR DURATION MEMORY)| SYS_TEMP_0FD9D6813_35DEEB |      1 |        |      0 |00:00:00.01 |       1 |  1024 |  1024 |          |         
|   3 |    COUNT                                 |                           |      1 |        |      9 |00:00:00.01 |       0 |       |       |          |         
|   4 |     CONNECT BY WITHOUT FILTERING         |                           |      1 |        |      9 |00:00:00.01 |       0 |  2048 |  2048 | 2048  (0)|         
|   5 |      FAST DUAL                           |                           |      1 |      1 |      1 |00:00:00.01 |       0 |       |       |          |         
|   6 |   NESTED LOOPS                           |                           |      1 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|   7 |    NESTED LOOPS                          |                           |      1 |      1 |     24 |00:00:00.01 |       0 |       |       |          |         
|   8 |     NESTED LOOPS                         |                           |      1 |      1 |     56 |00:00:00.01 |       0 |       |       |          |         
|   9 |      NESTED LOOPS                        |                           |      1 |      1 |     96 |00:00:00.01 |       0 |       |       |          |         
|  10 |       NESTED LOOPS                       |                           |      1 |      6 |    176 |00:00:00.01 |       0 |       |       |          |         
|  11 |        NESTED LOOPS                      |                           |      1 |     66 |    288 |00:00:00.01 |       0 |       |       |          |         
|  12 |         NESTED LOOPS                     |                           |      1 |      7 |     48 |00:00:00.01 |       0 |       |       |          |         
|  13 |          NESTED LOOPS                    |                           |      1 |     81 |     72 |00:00:00.01 |       0 |       |       |          |         
|  14 |           VIEW                           |                           |      1 |      9 |      9 |00:00:00.01 |       0 |       |       |          |         
|  15 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D6813_35DEEB |      1 |      9 |      9 |00:00:00.01 |       0 |       |       |          |         
|* 16 |           VIEW                           |                           |      9 |      9 |     72 |00:00:00.01 |       0 |       |       |          |         
|  17 |            TABLE ACCESS FULL             | SYS_TEMP_0FD9D6813_35DEEB |      9 |      9 |     81 |00:00:00.01 |       0 |       |       |          |         
|* 18 |          VIEW                            |                           |     72 |      1 |     48 |00:00:00.01 |       0 |       |       |          |         
|  19 |           TABLE ACCESS FULL              | SYS_TEMP_0FD9D6813_35DEEB |     72 |      9 |    648 |00:00:00.01 |       0 |       |       |          |         
|* 20 |         VIEW                             |                           |     48 |      9 |    288 |00:00:00.01 |       0 |       |       |          |         
|  21 |          TABLE ACCESS FULL               | SYS_TEMP_0FD9D6813_35DEEB |     48 |      9 |    432 |00:00:00.01 |       0 |       |       |          |         
|* 22 |        VIEW                              |                           |    288 |      1 |    176 |00:00:00.01 |       0 |       |       |          |         
|  23 |         TABLE ACCESS FULL                | SYS_TEMP_0FD9D6813_35DEEB |    288 |      9 |   2592 |00:00:00.01 |       0 |       |       |          |         
|* 24 |       VIEW                               |                           |    176 |      1 |     96 |00:00:00.01 |       0 |       |       |          |         
|  25 |        TABLE ACCESS FULL                 | SYS_TEMP_0FD9D6813_35DEEB |    176 |      9 |   1584 |00:00:00.01 |       0 |       |       |          |         
|* 26 |      VIEW                                |                           |     96 |      1 |     56 |00:00:00.01 |       0 |       |       |          |         
|  27 |       TABLE ACCESS FULL                  | SYS_TEMP_0FD9D6813_35DEEB |     96 |      9 |    864 |00:00:00.01 |       0 |       |       |          |         
|* 28 |     VIEW                                 |                           |     56 |      1 |     24 |00:00:00.01 |       0 |       |       |          |         
|  29 |      TABLE ACCESS FULL                   | SYS_TEMP_0FD9D6813_35DEEB |     56 |      9 |    504 |00:00:00.01 |       0 |       |       |          |         
|* 30 |    VIEW                                  |                           |     24 |      1 |      8 |00:00:00.01 |       0 |       |       |          |         
|  31 |     TABLE ACCESS FULL                    | SYS_TEMP_0FD9D6813_35DEEB |     24 |      9 |    216 |00:00:00.01 |       0 |       |       |          |         
-----------------------------------------------------------------------------------------------------------------------------------------------------------         
                                                                                                                                                                    
Predicate Information (identified by operation id):                                                                                                                 
---------------------------------------------------                                                                                                                 
                                                                                                                                                                    
  16 - filter("D1"."N"<>"D2"."N")                                                                                                                                   
  18 - filter(("D1"."N"<>"D3"."N" AND "D2"."N"<>"D3"."N" AND "D1"."N"+"D2"."N"+"D3"."N"=15))                                                                        
  20 - filter(("D1"."N"<>"D4"."N" AND "D2"."N"<>"D4"."N" AND "D3"."N"<>"D4"."N"))                                                                                   
  22 - filter(("D1"."N"<>"D7"."N" AND "D2"."N"<>"D7"."N" AND "D3"."N"<>"D7"."N" AND "D4"."N"<>"D7"."N" AND "D1"."N"+"D4"."N"+"D7"."N"=15))                          
  24 - filter(("D1"."N"<>"D5"."N" AND "D2"."N"<>"D5"."N" AND "D3"."N"<>"D5"."N" AND "D4"."N"<>"D5"."N" AND "D5"."N"<>"D7"."N" AND                                   
              "D3"."N"+"D5"."N"+"D7"."N"=15))                                                                                                                       
  26 - filter(("D1"."N"<>"D6"."N" AND "D2"."N"<>"D6"."N" AND "D3"."N"<>"D6"."N" AND "D4"."N"<>"D6"."N" AND "D5"."N"<>"D6"."N" AND                                   
              "D6"."N"<>"D7"."N" AND "D4"."N"+"D5"."N"+"D6"."N"=15))                                                                                                
  28 - filter(("D1"."N"<>"D8"."N" AND "D2"."N"<>"D8"."N" AND "D3"."N"<>"D8"."N" AND "D4"."N"<>"D8"."N" AND "D5"."N"<>"D8"."N" AND                                   
              "D6"."N"<>"D8"."N" AND "D7"."N"<>"D8"."N" AND "D2"."N"+"D5"."N"+"D8"."N"=15))                                                                         
  30 - filter(("D1"."N"<>"D9"."N" AND "D2"."N"<>"D9"."N" AND "D3"."N"<>"D9"."N" AND "D4"."N"<>"D9"."N" AND "D5"."N"<>"D9"."N" AND                                   
              "D6"."N"<>"D9"."N" AND "D7"."N"<>"D9"."N" AND "D8"."N"<>"D9"."N" AND "D3"."N"+"D6"."N"+"D9"."N"=15 AND "D1"."N"+"D5"."N"+"D9"."N"=15))                

This time I get some values in E-Rows - not at all perfect, but better than all the "1"s. Because of this, the optimizer recognizes that starting with D9,D8,D7... is not as good as starting with D1,D2,D3... Why does it recognize this? Because it wants to eliminate rows as fast as possible to keep the cost down, and the filter predicate in step 18 will filter away more rows when it starts with D1,D2,D3 than when it starts in the opposite direction.

Now it doesn't go straight in order this time - it goes D1, D2, D3, D4, D7, D5, D6, D8, D9. But that makes absolutely no difference for the A-Rows.

Now I've demonstrated the reason using the simpler 3x3 Magic Square. Then let me show a couple traces from the 4x4 Magic Square.

First the original with all the predicates in place:

select count(*) from (
with dat as (
   select level n from dual connect by rownum <=16
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8
     , d9.n n9, da.n na, db.n nb, dc.n nc, dd.n nd, de.n ne, df.n nf, dg.n ng
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8
     , dat d9, dat da, dat db, dat dc, dat dd, dat de, dat df, dat dg
 where not (
            d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d5.n in (d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d6.n in (d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d7.n in (d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d8.n in (d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d9.n in (da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or da.n in (db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or db.n in (dc.n, dd.n, de.n, df.n, dg.n)
         or dc.n in (dd.n, de.n, df.n, dg.n)
         or dd.n in (de.n, df.n, dg.n)
         or de.n in (df.n, dg.n)
         or df.n = dg.n
       )
   and d1.n + d2.n + d3.n + d4.n = 34
   and d5.n + d6.n + d7.n + d8.n = 34
   and d9.n + da.n + db.n + dc.n = 34
   and dd.n + de.n + df.n + dg.n = 34
   and d1.n + d5.n + d9.n + dd.n = 34
   and d2.n + d6.n + da.n + de.n = 34
   and d3.n + d7.n + db.n + df.n = 34
   and d4.n + d8.n + dc.n + dg.n = 34
   and d1.n + d6.n + db.n + dg.n = 34
   and d4.n + d7.n + da.n + dd.n = 34
)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          2           0
Fetch        2     96.36      97.50          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     96.36      97.50          0          0          2           1

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 120  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=0 pr=0 pw=0 time=97509244 us starts=1)
      7040       7040       7040   VIEW  (cr=0 pr=0 pw=0 time=94744145 us starts=1 cost=34 size=0 card=1)
      7040       7040       7040    TEMP TABLE TRANSFORMATION  (cr=0 pr=0 pw=0 time=94742345 us starts=1)
         0          0          0     LOAD AS SELECT (CURSOR DURATION MEMORY) SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=575 us starts=1)
        16         16         16      COUNT  (cr=0 pr=0 pw=0 time=191 us starts=1)
        16         16         16       CONNECT BY WITHOUT FILTERING (cr=0 pr=0 pw=0 time=159 us starts=1)
         1          1          1        FAST DUAL  (cr=0 pr=0 pw=0 time=0 us starts=1 cost=2 size=0 card=1)
      7040       7040       7040     NESTED LOOPS  (cr=0 pr=0 pw=0 time=94740277 us starts=1 cost=32 size=208 card=1)
      7040       7040       7040      NESTED LOOPS  (cr=0 pr=0 pw=0 time=94693163 us starts=1 cost=30 size=195 card=1)
    101520     101520     101520       NESTED LOOPS  (cr=0 pr=0 pw=0 time=168332973 us starts=1 cost=28 size=182 card=1)
    499264     499264     499264        NESTED LOOPS  (cr=0 pr=0 pw=0 time=358810209 us starts=1 cost=26 size=169 card=1)
    124816     124816     124816         NESTED LOOPS  (cr=0 pr=0 pw=0 time=89233888 us starts=1 cost=24 size=156 card=1)
    571808     571808     571808          NESTED LOOPS  (cr=0 pr=0 pw=0 time=112814919 us starts=1 cost=22 size=143 card=1)
   2793888    2793888    2793888           NESTED LOOPS  (cr=0 pr=0 pw=0 time=157320114 us starts=1 cost=20 size=130 card=1)
   9907200    9907200    9907200            NESTED LOOPS  (cr=0 pr=0 pw=0 time=210047939 us starts=1 cost=18 size=117 card=1)
   1238400    1238400    1238400             NESTED LOOPS  (cr=0 pr=0 pw=0 time=23592888 us starts=1 cost=16 size=104 card=1)
   2724480    2724480    2724480              NESTED LOOPS  (cr=0 pr=0 pw=0 time=3409757 us starts=1 cost=14 size=91 card=1)
    272448     272448     272448               NESTED LOOPS  (cr=0 pr=0 pw=0 time=383557 us starts=1 cost=12 size=78 card=1)
     24768      24768      24768                NESTED LOOPS  (cr=0 pr=0 pw=0 time=151690 us starts=1 cost=10 size=65 card=1)
      2064       2064       2064                 NESTED LOOPS  (cr=0 pr=0 pw=0 time=33527 us starts=1 cost=8 size=52 card=1)
      3360       3360       3360                  NESTED LOOPS  (cr=0 pr=0 pw=0 time=3647 us starts=1 cost=6 size=39 card=1)
       240        240        240                   NESTED LOOPS  (cr=0 pr=0 pw=0 time=392 us starts=1 cost=4 size=26 card=1)
        16         16         16                    VIEW  (cr=0 pr=0 pw=0 time=15 us starts=1 cost=2 size=13 card=1)
        16         16         16                     TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=11 us starts=1 cost=2 size=13 card=1)
       240        240        240                    VIEW  (cr=0 pr=0 pw=0 time=206 us starts=16 cost=2 size=13 card=1)
       256        256        256                     TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=112 us starts=16 cost=2 size=13 card=1)
      3360       3360       3360                   VIEW  (cr=0 pr=0 pw=0 time=2074 us starts=240 cost=2 size=13 card=1)
      3840       3840       3840                    TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=932 us starts=240 cost=2 size=13 card=1)
      2064       2064       2064                  VIEW  (cr=0 pr=0 pw=0 time=18049 us starts=3360 cost=2 size=13 card=1)
     53760      53760      53760                   TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=9122 us starts=3360 cost=2 size=13 card=1)
     24768      24768      24768                 VIEW  (cr=0 pr=0 pw=0 time=18807 us starts=2064 cost=2 size=13 card=1)
     33024      33024      33024                  TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=4645 us starts=2064 cost=2 size=13 card=1)
    272448     272448     272448                VIEW  (cr=0 pr=0 pw=0 time=155297 us starts=24768 cost=2 size=13 card=1)
    396288     396288     396288                 TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=60927 us starts=24768 cost=2 size=13 card=1)
   2724480    2724480    2724480               VIEW  (cr=0 pr=0 pw=0 time=1494126 us starts=272448 cost=2 size=13 card=1)
   4359168    4359168    4359168                TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=614327 us starts=272448 cost=2 size=13 card=1)
   1238400    1238400    1238400              VIEW  (cr=0 pr=0 pw=0 time=13458558 us starts=2724480 cost=2 size=13 card=1)
  43591680   43591680   43591680               TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=6029761 us starts=2724480 cost=2 size=13 card=1)
   9907200    9907200    9907200             VIEW  (cr=0 pr=0 pw=0 time=6350502 us starts=1238400 cost=2 size=13 card=1)
  19814400   19814400   19814400              TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=2798118 us starts=1238400 cost=2 size=13 card=1)
   2793888    2793888    2793888            VIEW  (cr=0 pr=0 pw=0 time=49949556 us starts=9907200 cost=2 size=13 card=1)
 158515200  158515200  158515200             TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=22244518 us starts=9907200 cost=2 size=13 card=1)
    571808     571808     571808           VIEW  (cr=0 pr=0 pw=0 time=14246770 us starts=2793888 cost=2 size=13 card=1)
  44702208   44702208   44702208            TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=6318647 us starts=2793888 cost=2 size=13 card=1)
    124816     124816     124816          VIEW  (cr=0 pr=0 pw=0 time=2905447 us starts=571808 cost=2 size=13 card=1)
   9148928    9148928    9148928           TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=1320798 us starts=571808 cost=2 size=13 card=1)
    499264     499264     499264         VIEW  (cr=0 pr=0 pw=0 time=561519 us starts=124816 cost=2 size=13 card=1)
   1997056    1997056    1997056          TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=284936 us starts=124816 cost=2 size=13 card=1)
    101520     101520     101520        VIEW  (cr=0 pr=0 pw=0 time=2480948 us starts=499264 cost=2 size=13 card=1)
   7988224    7988224    7988224         TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=1114340 us starts=499264 cost=2 size=13 card=1)
      7040       7040       7040       VIEW  (cr=0 pr=0 pw=0 time=517675 us starts=101520 cost=2 size=13 card=1)
   1624320    1624320    1624320        TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=238626 us starts=101520 cost=2 size=13 card=1)
      7040       7040       7040      VIEW  (cr=0 pr=0 pw=0 time=37907 us starts=7040 cost=2 size=13 card=1)
    112640     112640     112640       TABLE ACCESS FULL SYS_TEMP_0FD9D67F3_35DEEB (cr=0 pr=0 pw=0 time=19038 us starts=7040 cost=2 size=13 card=1)

And then the "bad" run with the single predicated removed:

select count(*) from (
with dat as (
   select level n from dual connect by rownum <=16
)
select d1.n n1, d2.n n2, d3.n n3, d4.n n4, d5.n n5, d6.n n6, d7.n n7, d8.n n8
     , d9.n n9, da.n na, db.n nb, dc.n nc, dd.n nd, de.n ne, df.n nf, dg.n ng
  from dat d1, dat d2, dat d3, dat d4, dat d5, dat d6, dat d7, dat d8
     , dat d9, dat da, dat db, dat dc, dat dd, dat de, dat df, dat dg
 where not (
            d1.n in (d2.n, d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d2.n in (d3.n, d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d3.n in (d4.n, d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d4.n in (d5.n, d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d5.n in (d6.n, d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d6.n in (d7.n, d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d7.n in (d8.n, d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d8.n in (d9.n, da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or d9.n in (da.n, db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or da.n in (db.n, dc.n, dd.n, de.n, df.n, dg.n)
         or db.n in (dc.n, dd.n, de.n, df.n, dg.n)
         or dc.n in (dd.n, de.n, df.n, dg.n)
         or dd.n in (de.n, df.n, dg.n)
         or de.n in (df.n, dg.n)
         or df.n = dg.n
       )
   and d1.n + d2.n + d3.n + d4.n = 34
   and d5.n + d6.n + d7.n + d8.n = 34
   and d9.n + da.n + db.n + dc.n = 34
--   and dd.n + de.n + df.n + dg.n = 34 -- by logic of magic square this is not needed
   and d1.n + d5.n + d9.n + dd.n = 34
   and d2.n + d6.n + da.n + de.n = 34
   and d3.n + d7.n + db.n + df.n = 34
   and d4.n + d8.n + dc.n + dg.n = 34
   and d1.n + d6.n + db.n + dg.n = 34
   and d4.n + d7.n + da.n + dd.n = 34
)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.05       0.05          0          0          0           0
Execute      1      0.00       0.00          0          0          2           0
Fetch        2   2252.10    2267.16          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4   2252.16    2267.22          0          0          2           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 120  
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=0 pr=0 pw=0 time=633018189 us starts=1)
      7040       7040       7040   VIEW  (cr=0 pr=0 pw=0 time=1865657286 us starts=1 cost=34 size=0 card=1)
      7040       7040       7040    TEMP TABLE TRANSFORMATION  (cr=0 pr=0 pw=0 time=1865655494 us starts=1)
         0          0          0     LOAD AS SELECT (CURSOR DURATION MEMORY) SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=124 us starts=1)
        16         16         16      COUNT  (cr=0 pr=0 pw=0 time=73 us starts=1)
        16         16         16       CONNECT BY WITHOUT FILTERING (cr=0 pr=0 pw=0 time=56 us starts=1)
         1          1          1        FAST DUAL  (cr=0 pr=0 pw=0 time=0 us starts=1 cost=2 size=0 card=1)
      7040       7040       7040     NESTED LOOPS  (cr=0 pr=0 pw=0 time=1865654037 us starts=1 cost=32 size=208 card=1)
     64256      64256      64256      NESTED LOOPS  (cr=0 pr=0 pw=0 time=2198515667 us starts=1 cost=30 size=195 card=1)
   1563792    1563792    1563792       NESTED LOOPS  (cr=0 pr=0 pw=0 time=100153417 us starts=1 cost=28 size=182 card=1)
  11436160   11436160   11436160        NESTED LOOPS  (cr=0 pr=0 pw=0 time=146692379 us starts=1 cost=26 size=169 card=1)
   2859040    2859040    2859040         NESTED LOOPS  (cr=0 pr=0 pw=0 time=2147225666 us starts=1 cost=24 size=156 card=1)
  13144320   13144320   13144320          NESTED LOOPS  (cr=0 pr=0 pw=0 time=2404199888 us starts=1 cost=22 size=143 card=1)
  58786560   58786560   58786560           NESTED LOOPS  (cr=0 pr=0 pw=0 time=3560182476 us starts=1 cost=20 size=130 card=1)
 196162560  196162560  196162560            NESTED LOOPS  (cr=0 pr=0 pw=0 time=898106419 us starts=1 cost=18 size=117 card=1)
  24520320   24520320   24520320             NESTED LOOPS  (cr=0 pr=0 pw=0 time=584900526 us starts=1 cost=16 size=104 card=1)
  57657600   57657600   57657600              NESTED LOOPS  (cr=0 pr=0 pw=0 time=77775396 us starts=1 cost=14 size=91 card=1)
   5765760    5765760    5765760               NESTED LOOPS  (cr=0 pr=0 pw=0 time=7117215 us starts=1 cost=12 size=78 card=1)
    524160     524160     524160                NESTED LOOPS  (cr=0 pr=0 pw=0 time=1176729 us starts=1 cost=10 size=65 card=1)
     43680      43680      43680                 NESTED LOOPS  (cr=0 pr=0 pw=0 time=70516 us starts=1 cost=8 size=52 card=1)
      3360       3360       3360                  NESTED LOOPS  (cr=0 pr=0 pw=0 time=5735 us starts=1 cost=6 size=39 card=1)
       240        240        240                   NESTED LOOPS  (cr=0 pr=0 pw=0 time=249 us starts=1 cost=4 size=26 card=1)
        16         16         16                    VIEW  (cr=0 pr=0 pw=0 time=4 us starts=1 cost=2 size=13 card=1)
        16         16         16                     TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=4 us starts=1 cost=2 size=13 card=1)
       240        240        240                    VIEW  (cr=0 pr=0 pw=0 time=206 us starts=16 cost=2 size=13 card=1)
       256        256        256                     TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=59 us starts=16 cost=2 size=13 card=1)
      3360       3360       3360                   VIEW  (cr=0 pr=0 pw=0 time=3030 us starts=240 cost=2 size=13 card=1)
      3840       3840       3840                    TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=708 us starts=240 cost=2 size=13 card=1)
     43680      43680      43680                  VIEW  (cr=0 pr=0 pw=0 time=50987 us starts=3360 cost=2 size=13 card=1)
     53760      53760      53760                   TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=20408 us starts=3360 cost=2 size=13 card=1)
    524160     524160     524160                 VIEW  (cr=0 pr=0 pw=0 time=423413 us starts=43680 cost=2 size=13 card=1)
    698880     698880     698880                  TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=153332 us starts=43680 cost=2 size=13 card=1)
   5765760    5765760    5765760                VIEW  (cr=0 pr=0 pw=0 time=3921047 us starts=524160 cost=2 size=13 card=1)
   8386560    8386560    8386560                 TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=1618513 us starts=524160 cost=2 size=13 card=1)
  57657600   57657600   57657600               VIEW  (cr=0 pr=0 pw=0 time=36974201 us starts=5765760 cost=2 size=13 card=1)
  92252160   92252160   92252160                TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=15791110 us starts=5765760 cost=2 size=13 card=1)
  24520320   24520320   24520320              VIEW  (cr=0 pr=0 pw=0 time=325111970 us starts=57657600 cost=2 size=13 card=1)
 922521600  922521600  922521600               TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=154158949 us starts=57657600 cost=2 size=13 card=1)
 196162560  196162560  196162560             VIEW  (cr=0 pr=0 pw=0 time=146189046 us starts=24520320 cost=2 size=13 card=1)
 392325120  392325120  392325120              TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=64255241 us starts=24520320 cost=2 size=13 card=1)
  58786560   58786560   58786560            VIEW  (cr=0 pr=0 pw=0 time=1135385802 us starts=196162560 cost=2 size=13 card=1)
3138600960 3138600960 3138600960             TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=527151424 us starts=196162560 cost=2 size=13 card=1)
  13144320   13144320   13144320           VIEW  (cr=0 pr=0 pw=0 time=336873570 us starts=58786560 cost=2 size=13 card=1)
 940584960  940584960  940584960            TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=153398356 us starts=58786560 cost=2 size=13 card=1)
   2859040    2859040    2859040          VIEW  (cr=0 pr=0 pw=0 time=75468610 us starts=13144320 cost=2 size=13 card=1)
 210309120  210309120  210309120           TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=35268356 us starts=13144320 cost=2 size=13 card=1)
  11436160   11436160   11436160         VIEW  (cr=0 pr=0 pw=0 time=14798120 us starts=2859040 cost=2 size=13 card=1)
  45744640   45744640   45744640          TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=7947929 us starts=2859040 cost=2 size=13 card=1)
   1563792    1563792    1563792        VIEW  (cr=0 pr=0 pw=0 time=64166311 us starts=11436160 cost=2 size=13 card=1)
 182978560  182978560  182978560         TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=30302323 us starts=11436160 cost=2 size=13 card=1)
     64256      64256      64256       VIEW  (cr=0 pr=0 pw=0 time=8953514 us starts=1563792 cost=2 size=13 card=1)
  25020672   25020672   25020672        TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=4203353 us starts=1563792 cost=2 size=13 card=1)
      7040       7040       7040      VIEW  (cr=0 pr=0 pw=0 time=386082 us starts=64256 cost=2 size=13 card=1)
   1028096    1028096    1028096       TABLE ACCESS FULL SYS_TEMP_0FD9D67F4_35DEEB (cr=0 pr=0 pw=0 time=181686 us starts=64256 cost=2 size=13 card=1)

The good case generated 158,515,200 rows at the "largest" step - the bad case generated 3,138,600,960 rows. That's almost 20 times more, so adding that a lot of the other steps also got "bloated", this accounts for the more than factor 23 increase in elapsed time.

Luckily this is a very special case - not really something you can expect the optimizer to reasonably figure out. But there are still lessons to be learned from this that might come in useful from time to time.

My lesson is mostly, that it seldoms pays to withhold information from the optimizer :-)

No comments:

Post a Comment