What seems odd to me is that in different kinds of tests (with different frequency of column values):


i1 Rows Removed by Filter = 900156, 179792, 89762 (decreased a lot)
i1 buffers = 46983, 44373, 39928 (decreased, but not a lot)
i1 best case time = 756.045, 127.814, 79.492 (decreased a lot, as well as probably average case too)
i1 cost estimates = 67358.15, 48809.34, 46544.80 (did not decrease a lot)

i2 Rows Removed by Filter = 900835, 980350, 991389
i2 buffers = 46985, 46985, 46987
i2 best case time = 377.554, 346.481, 387.874
i2 cost estimates = 39166.34, 39247.83, 40167.34

It's odd that increase in actual execution time for "i1" was not reflected enough in cost estimates. The cost even didn't go below "i2" costs.

I've added some logging, in order to get the actual numbers which were used for estimation.

--drop table if exists aaa;
--create table aaa as select floor(random()*100)::int num, (random()*10 < 1)::int flag from generate_series(1, 10000000) id;
--analyze aaa;

--set enable_bitmapscan = off; set enable_indexscan = on;  set enable_seqscan = off; --set seq_page_cost = 1.0; set random_page_cost = 1.0; set cpu_tuple_cost = 0.01; set cpu_index_tuple_cost = 0.005; set cpu_operator_cost = 0.0025;

--create index i1 on aaa  (num);
--drop index if exists i2;
--explain (analyze,verbose,costs,buffers) select * from aaa where num = 1 and flag = 1;

Index Scan using i1 on public.aaa  (cost=0.43..46697.59 rows=10641 width=8) (actual time=0.047..153.521 rows=9826 loops=1)
  Rows Removed by Filter: 89948

--drop index if exists i1;
--create index i2 on aaa  (flag);
--explain (analyze,verbose,costs,buffers) select * from aaa where num = 1 and flag = 1;

Index Scan using i2 on public.aaa  (cost=0.43..39583.11 rows=10641 width=8) (actual time=0.098..351.454 rows=9826 loops=1)
  Rows Removed by Filter: 990249


LOG:  cost_index:
        seq_page_cost=1.00, random_page_cost=1.00, cpu_tuple_cost=0.0100, cpu_index_tuple_cost=0.0050, cpu_operator_cost=0.0025, effective_cache_size=131072         indexStartupCost=0.43, indexTotalCost=1103.94, indexSelectivity=0.01076667, indexCorrelation=0.00208220         baserel->tuples=10000033.00, baserel->pages=44248.00, baserel->allvisfrac=0.00000000
        tuples_fetched=107667.00, pages_fetched=477.00
        max_IO_cost=44248.0000, min_IO_cost=477.0000, csquared=0.0000
        qpqual_cost.startup=0.0000, qpqual_cost.per_tuple=0.0025, cpu_per_tuple=0.0125
        spc_seq_page_cost=1.00, spc_random_page_cost=1.00
        startup_cost=0.43, total_cost=46697.59

LOG:  cost_index:
        seq_page_cost=1.00, random_page_cost=1.00, cpu_tuple_cost=0.0100, cpu_index_tuple_cost=0.0050, cpu_operator_cost=0.0025, effective_cache_size=131072         indexStartupCost=0.43, indexTotalCost=10123.93, indexSelectivity=0.09883333, indexCorrelation=0.82505685         baserel->tuples=10000000.00, baserel->pages=44248.00, baserel->allvisfrac=0.00000000
        tuples_fetched=988333.00, pages_fetched=4374.00
        max_IO_cost=44248.0000, min_IO_cost=4374.0000, csquared=0.6807
        qpqual_cost.startup=0.0000, qpqual_cost.per_tuple=0.0025, cpu_per_tuple=0.0125
        spc_seq_page_cost=1.00, spc_random_page_cost=1.00
        startup_cost=0.43, total_cost=39583.11


Here is a break down of the total_cost into components, for i1 query and for i2 query (some rounding was removed from the formula for brevity):

path->path.total_cost =
  (indexTotalCost + qpqual_cost.startup) +
  (max_IO_cost + csquared * (min_IO_cost - max_IO_cost)) +
  (cpu_tuple_cost + qpqual_cost.per_tuple) * (indexSelectivity * baserel->tuples);
path->path.total_cost =
  1103.94 + 0.0000 +                                // 1103.94 +
  44248.0000 + 0.0000 * (477.0000 - 44248.0000) +   // 44248.00 +
  (0.0100 + 0.0025) * (0.01076667 * 10000033.00)    // 1345.84
  = 46697.78;                                       // = 46697.78;

path->path.total_cost =
  (indexTotalCost + qpqual_cost.startup) +
  (max_IO_cost + csquared * (min_IO_cost - max_IO_cost)) +
  (cpu_tuple_cost + qpqual_cost.per_tuple) * (indexSelectivity * baserel->tuples);
path->path.total_cost =
  10123.93 + 0.0000 +                               // 10123.93 +
  44248.0000 + 0.6807 * (4374.0000 - 44248.0000) +  // 17105.77 +
  (0.0100 + 0.0025) * (0.09883333 * 10000000.00)    // 12354.17
  = 39583.86;                                       // = 39583.86;


PS.
The code used for logging:
/postgresql-9.3.1/src/backend/optimizer/path/costsize.c : cost_index()

    ereport(LOG,
            (errmsg("cost_index: \n"
                    "seq_page_cost=%.2f, random_page_cost=%.2f, cpu_tuple_cost=%.4f, cpu_index_tuple_cost=%.4f, cpu_operator_cost=%.4f, effective_cache_size=%.0f\n"                     "indexStartupCost=%.2f, indexTotalCost=%.2f, indexSelectivity=%.8f, indexCorrelation=%.8f\n"                     "baserel->tuples=%.2f, baserel->pages=%.2f, baserel->allvisfrac=%.8f\n"
                    "tuples_fetched=%.2f, pages_fetched=%.2f\n"
                    "max_IO_cost=%.4f, min_IO_cost=%.4f, csquared=%.4f\n"
                    "qpqual_cost.startup=%.4f, qpqual_cost.per_tuple=%.4f, cpu_per_tuple=%.4f\n"
                    "spc_seq_page_cost=%.2f, spc_random_page_cost=%.2f\n"
                    "startup_cost=%.2f, total_cost=%.2f\n",

                    seq_page_cost, random_page_cost, cpu_tuple_cost, cpu_index_tuple_cost, cpu_operator_cost, (double)effective_cache_size,                     indexStartupCost, indexTotalCost, indexSelectivity, indexCorrelation,                     baserel->tuples, (double) baserel->pages, baserel->allvisfrac,
                    tuples_fetched, pages_fetched,
                    max_IO_cost, min_IO_cost, csquared,
                    qpqual_cost.startup, qpqual_cost.per_tuple, cpu_per_tuple,
                    spc_seq_page_cost, spc_random_page_cost,
                    startup_cost, startup_cost + run_cost
                    )));

Regards,
Vitaliy

Reply via email to