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'?
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?
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.
