Re: Estimates on partial index

2016-08-18 23:06 GMT+03:00 Jeff Janes <jeff(dot)janes(at)gmail(dot)com>:

> It does account for them, but perhaps not perfectly. See "[PERFORM]
> index fragmentation on insert-only table with non-unique column" for
> some arguments on that which might be relevant to you.
>

Thanks for pointing this out, good stuff to know.

If you can come up with a data generator which creates data that
> others can use to reproduce this situation, we can then investigate it
> in more detail.
>

I do not think this has any value anymore. I have reconfigured the server:
- r_p_c returned to the default 4.0
- turned on track_io_timing
- reindexed all indexes on the table
- went with the suggestion from Jim about partial index on `due_date`,
although
delayed it a bit to get a better view on the situation

Running several explains in a row produces the following:

Index Scan using idx_loan_agreemnets_loan_id_cond_is_current_true on
loan_agreements la (cost=0.42..21469.40 rows=224331 width=13) (actual
time=0.040..2687.422 rows=216440 loops=1)
Filter: ('2016-08-11'::date > due_date)
Rows Removed by Filter: 21806
Buffers: shared hit=226670 read=692 dirtied=48
I/O Timings: read=9.854
Planning time: 1885.219 ms
Execution time: 2712.833 ms

Index Scan using idx_loan_agreemnets_loan_id_cond_is_current_true on
loan_agreements la (cost=0.42..21469.40 rows=224331 width=13) (actual
time=426.027..2273.617 rows=216440 loops=1)
Filter: ('2016-08-11'::date > due_date)
Rows Removed by Filter: 21806
Buffers: shared hit=227276
Planning time: 0.175 ms
Execution time: 2296.414 ms

Index Scan using idx_loan_agreemnets_loan_id_cond_is_current_true on
loan_agreements la (cost=0.42..21469.40 rows=224331 width=13) (actual
time=0.034..297.113 rows=216440 loops=1)
Filter: ('2016-08-11'::date > due_date)
Rows Removed by Filter: 21806
Buffers: shared hit=227276
Planning time: 0.173 ms
Execution time: 310.509 ms

Index Scan using idx_loan_agreemnets_loan_id_cond_is_current_true on
loan_agreements la (cost=0.42..21469.40 rows=224331 width=13) (actual
time=0.031..286.212 rows=216440 loops=1)
Filter: ('2016-08-11'::date > due_date)
Rows Removed by Filter: 21806
Buffers: shared hit=227276
Planning time: 0.163 ms
Execution time: 299.831 ms

This makes me think, that IO is not my issue here and, honestly, I have no
clue what can be behind this.

What I noticed — queries do experience this kind of hiccups from time to
time. CPU and IO monitoring shows no spikes at all, CPU is below 40% all
the time.
Currently I am trying to find out ways how to track down what's going on
here.

Still — thanks everyone for the feedback, it was valuable for me!

--
Victor Y. Yegorov