On Tue, Jan 22, 2013 at 1:41 AM, Andrew Dunstan <and...@dunslane.net> wrote:
> > On 01/21/2013 10:05 AM, rudi wrote: > >> Hello, >> >> I'm running postgresl 9.0. After partitioning a big table, CPU usage >> raised from average 5-10% to average 70-80%. >> >> - the table contains about 20.000.000 rows >> - partitions are selected using a trigger, based on an indexed field, a >> date (IF date_taken >= x AND date_taken < y) >> - I created 5 partitions, the 2012 one now contains most of the rows. The >> 2013 partition is the "live" partition, mostly insert, a few select based >> on the above indexed field. The 2013, 2014, 2015 partitions are empty >> - constraint execution is on. >> I have 2 weeks CPU usage reports and the pattern definately changed after >> I made the partitions. Any idea? >> >> >> > Well, the first question that comes to my mind is whether it's the inserts > that are causing the load or the reads. If it's the inserts then you should > show us the whole trigger. Does it by any chance use 'execute'? I think I found the culprit. The insert trigger doesn't seem to be an issue. It is a trivial IF-ELSE and inserts seems fast. IF (NEW.date_taken < DATE '2013-01-01') THEN INSERT INTO sb_logs_2012 VALUES (NEW.*); ELSIF (NEW.date_taken >= DATE '2013-01-01' AND NEW.date_taken < DATE '2014-01-01') THEN INSERT INTO sb_logs_2013 VALUES (NEW.*); [...] END IF; Every query has been carefully optimized, child tables are indexed. The table(s) has a UNIQUE index on ("date_taken", "device_id") and "date_taken" is the partitioning column (one partition per year). There are few well known access path to this table: INSERTs (40-50.000 each day), SELECTs on a specific device_id AND on a specific day. BUT, I discovered an access path used by a process every few secs. to get the last log for a given device, and this query became really slow after partitioning: Result (cost=341156.04..341182.90 rows=4 width=86) (actual time=1132.326..1132.329 rows=1 loops=1) InitPlan 1 (returns $0) -> Aggregate (cost=341156.03..341156.04 rows=1 width=8) (actual time=1132.295..1132.296 rows=1 loops=1) -> Append (cost=0.00..341112.60 rows=17371 width=8) (actual time=45.600..1110.057 rows=19016 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=45.599..1060.143 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..21663.39 rows=1363 width=8) (actual time=0.022..47.661 rows=1199 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.011..0.011 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.008..0.008 rows=0 loops=1) Index Cond: (device_id = 901) -> Append (cost=0.00..26.86 rows=4 width=86) (actual time=1132.325..1132.328 rows=1 loops=1) -> Seq Scan on sb_logs (cost=0.00..0.00 rows=1 width=90) (actual time=0.002..0.002 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=1132.314..1132.314 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.007..0.008 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.002..0.002 rows=0 loops=1) Index Cond: ((date_taken = $0) AND (device_id = 901)) Total runtime: 1132.436 ms I must find a better way to get that information, but I wonder if there could be a better plan. The same query over a table with the same structure but not partitioned gives far better 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.065..0.066 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.059..0.059 rows=1 loops=1) InitPlan 1 (returns $0) -> Limit (cost=0.00..12.34 rows=1 width=8) (actual time=0.055..0.056 rows=1 loops=1) -> Index Scan Backward using index_iv_logs_on_date_taken_and_device_id on iv_logs (cost=0.00..261052.53 rows=21154 width=8) (actual time=0.055..0.055 rows=1 loops=1) Index Cond: ((date_taken IS NOT NULL) AND (device_id = 1475)) Total runtime: 0.110 ms -- rd This is the way the world ends. Not with a bang, but a whimper.