Re: High CPU usage after partitioning

On Tue, Jan 22, 2013 at 3:04 PM, Merlin Moncure <mmoncure(at)gmail(dot)com> wrote:

> let's see the query -- it's probably written in such a way so as to
> not be able to be optimized through CE.
>
>
The query is pretty simple and standard, the behaviour (and the plan) is
totally different when it comes to a partitioned table.

Partioned table query => explain analyze SELECT "sb_logs".* FROM "sb_logs"
WHERE (device_id = 901 AND date_taken = (SELECT MAX(date_taken) FROM
sb_logs WHERE device_id = 901));
Plain table query => explain analyze SELECT "iv_logs".* FROM "iv_logs"
WHERE (device_id = 1475 AND date_taken = (SELECT MAX(date_taken) FROM
iv_logs WHERE device_id = 1475));

sb_logs and iv_logs have identical index structure and similar cardinality
(about ~12.000.000 rows the first, ~9.000.000 rows the second).

sb_logs PLAN:
InitPlan 1 (returns $0)
-> Aggregate (cost=339424.47..339424.48 rows=1 width=8) (actual
time=597.742..597.742 rows=1 loops=1)
-> Append (cost=0.00..339381.68 rows=17114 width=8) (actual
time=42.791..594.001 rows=19024 loops=1)
-> Seq Scan on sb_logs (cost=0.00..0.00 rows=1 width=8)
(actual time=0.000..0.000 rows=0 loops=1)
Filter: (device_id = 901)
-> Index Scan using
sb_logs_2012_on_date_taken_and_device_id on sb_logs_2012 sb_logs
(cost=0.00..319430.51 rows=16003 width=8) (actual time=42.789..559.165
rows=17817 loops=1)
Index Cond: (device_id = 901)
-> Index Scan using
sb_logs_2013_on_date_taken_and_device_id on sb_logs_2013 sb_logs
(cost=0.00..19932.46 rows=1106 width=8) (actual time=0.037..31.699
rows=1207 loops=1)
Index Cond: (device_id = 901)
-> Bitmap Heap Scan on sb_logs_2014 sb_logs
(cost=10.25..18.71 rows=4 width=8) (actual time=0.012..0.012 rows=0
loops=1)
Recheck Cond: (device_id = 901)
-> Bitmap Index Scan on
sb_logs_2014_on_date_taken_and_device_id (cost=0.00..10.25 rows=4 width=0)
(actual time=0.010..0.010 rows=0 loops=1)
Index Cond: (device_id = 901)
-> Append (cost=0.00..26.86 rows=4 width=86) (actual
time=597.808..597.811 rows=1 loops=1)
-> Seq Scan on sb_logs (cost=0.00..0.00 rows=1 width=90) (actual
time=0.022..0.022 rows=0 loops=1)
Filter: ((device_id = 901) AND (date_taken = $0))
-> Index Scan using sb_logs_2012_on_date_taken_and_device_id on
sb_logs_2012 sb_logs (cost=0.00..10.20 rows=1 width=90) (actual
time=597.773..597.773 rows=0 loops=1)
Index Cond: ((date_taken = $0) AND (device_id = 901))
-> Index Scan using sb_logs_2013_on_date_taken_and_device_id on
sb_logs_2013 sb_logs (cost=0.00..8.39 rows=1 width=91) (actual
time=0.011..0.011 rows=1 loops=1)
Index Cond: ((date_taken = $0) AND (device_id = 901))
-> Index Scan using sb_logs_2014_on_date_taken_and_device_id on
sb_logs_2014 sb_logs (cost=0.00..8.27 rows=1 width=72) (actual
time=0.003..0.003 rows=0 loops=1)
Index Cond: ((date_taken = $0) AND (device_id = 901))
Total runtime: 598.049 ms

iv_logs PLAN:

Index Scan using index_iv_logs_on_date_taken_and_device_id on iv_logs
(cost=12.35..21.88 rows=1 width=157) (actual time=0.060..0.060 rows=1
loops=1)
Index Cond: ((date_taken = $1) AND (device_id = 1475))
InitPlan 2 (returns $1)
-> Result (cost=12.34..12.35 rows=1 width=0) (actual
time=0.053..0.053 rows=1 loops=1)
InitPlan 1 (returns $0)
-> Limit (cost=0.00..12.34 rows=1 width=8) (actual
time=0.050..0.051 rows=1 loops=1)
-> Index Scan Backward using
index_iv_logs_on_date_taken_and_device_id on iv_logs (cost=0.00..261151.32
rows=21163 width=8) (actual time=0.046..0.046 rows=1 loops=1)
Index Cond: ((date_taken IS NOT NULL) AND
(device_id = 1475))
Total runtime: 0.101 ms

--
rd

This is the way the world ends.
Not with a bang, but a whimper.