Explore our sites

Stack Exchange
tour help
Tell me more ×
Stack Overflow is a question and answer site for professional and enthusiast programmers. It's 100% free, no registration required.
up vote 1 down vote favorite

I'm experiencing strange PostgreSQL behavior. I have partitioned history table into smaller pieces based on time History -> History_part_YYYY-MM

Check constraints:
"History_part_2013-11_sentdate_check" CHECK (sentdate >= '2013-11-01 00:00:00-04'::timestamp with time zone AND sentdate < '2013-12-01 00:00:00-05'::timestamp with time zone)

Inherits: "History"

Each partition has its own index on transaction_id column.

History_part_2013-11_transaction_id_idx" btree (transaction_id)

It is as far as I know 'nothing special' way of partitioning, taken from postgres tutorial.

What the problem is that executing this query is slow:

SELECT * FROM "History" WHERE transaction_id = 'MMS-dev-23599-2013-12-11-13:03:53.349735' LIMIT 1;

I was able to narrow the problem down that this query is slow only FIRST TIME per script, if it is run second time it is fast. If it is run again in separate script it is slow again and second run (in script) will be fast again... I really have no explanation for this. It is not inside any transaction.

Here are sample execution times of two queries run one by one in same script:

1.33s   SELECT * FROM "History" WHERE transaction_id = 'MMS-dev-14970-2013-12-11-13:18:29.889376' LIMIT 1;...
0.019s  SELECT * FROM "History" WHERE transaction_id = 'MMS-dev-14970-2013-12-11-13:18:29.889376' LIMIT 1;

The first query is that slow that is trigger 'explain analyze' call and that looks like this (and is really really fast too):

    Limit  (cost=0.00..8.07 rows=1 width=2589) (actual time=0.972..0.973 rows=1 loops=1)
  ->  Result  (cost=0.00..581.07 rows=72 width=2589) (actual time=0.964..0.964 rows=1 loops=1)
        ->  Append  (cost=0.00..581.07 rows=72 width=2589) (actual time=0.958..0.958 rows=1 loops=1)
              ->  Seq Scan on "History"  (cost=0.00..1.00 rows=1 width=3760) (actual time=0.015..0.015 rows=0 loops=1)
                    Filter: ((transaction_id)::text = 'MMS-dev-23595-2013-12-11-13:20:10.422306'::text)
              ->  Index Scan using "History_part_2013-10_transaction_id_idx" on "History_part_2013-10" "History"  (cost=0.00..8.28 rows=1 width=1829) (actual time=0.040..0.040 rows=0 loops=1)
                    Index Cond: ((transaction_id)::text = 'MMS-dev-23595-2013-12-11-13:20:10.422306'::text)
              ->  Index Scan using "History_part_2013-02_transaction_id_idx" on "History_part_2013-02" "History"  (cost=0.00..8.32 rows=1 width=1707) (actual time=0.021..0.021 rows=0 loops=1)
                    Index Cond: ((transaction_id)::text = 'MMS-dev-23595-2013-12-11-13:20:10.422306'::text)

.... and it check all tables (around 54 now - few tables are empty created for future ) and at the end

->  Index Scan using "History_part_2014-10_transaction_id_idx" on "History_part_2014-10" "History"  (cost=0.00..8.27 rows=1 width=3760) (never executed)
                    Index Cond: ((transaction_id)::text = 'MMS-dev-23595-2013-12-11-13:20:10.422306'::text)

Total runtime: 6.390 ms

The Total runtime is 0,006s and the first query is always above 1s - if there is more concurrent scripts running (each with UNIQUE transaction_id) first execution can go up to 20s and the second execution is at few miliseconds.

Did anyone experience that? I wonder if there is something wrong I am doing or maybe this is postgres issue??

I upgraded postgres from 9.2.4 -> 9.2.5 - it seems it is slightly better but the issue definitely remains.

UPDATE: I use this query now:

SELECT * FROM "History" WHERE transaction_id = 'MMS-live-15425-2013-18-11-17:32:20.917198' AND sentdate>='2013-10-18' AND sentdate<'2013-11-19' LIMIT 1

First time it is run in the script - 3 to 8 SECONDS when many queries run at once against this table (if there s only on script at a time it is much faster).

When I change first query in script to (calls the partition table directly):

SELECT * FROM "History_part_2013-11" WHERE transaction_id = 'MMS-live-15425-2013-18-11-17:32:20.917198' AND sentdate>='2013-10-18' AND sentdate<'2013-11-19' LIMIT 1

It is like 0.03s - much faster BUT the next query in the script that uses query against "History" table is still around 3-8 SECONDS.

Here is the explain analyze of the first query against "History"

    Limit  (cost=0.00..25.41 rows=1 width=2540) (actual time=0.129..0.130 rows=1 loops=1)
  ->  Result  (cost=0.00..76.23 rows=3 width=2540) (actual time=0.121..0.121 rows=1 loops=1)
        ->  Append  (cost=0.00..76.23 rows=3 width=2540) (actual time=0.117..0.117 rows=1 loops=1)
              ->  Seq Scan on "History"  (cost=0.00..58.00 rows=1 width=3750) (actual time=0.060..0.060 rows=0 loops=1)
                    Filter: ((sentdate >= '2013-10-18 00:00:00-04'::timestamp with time zone) AND (sentdate < '2013-11-19 00:00:00-05'::timestamp with time zone) AND ((transaction_id)::text = 'MMS-live-15425-2013-18-11-17:32:20.917198'::text))
              ->  Index Scan using "History_part_2013-11_transaction_id_idx" on "History_part_2013-11" "History"  (cost=0.00..8.36 rows=1 width=1985) (actual time=0.051..0.051 rows=1 loops=1)
                    Index Cond: ((transaction_id)::text = 'MMS-live-15425-2013-18-11-17:32:20.917198'::text)
                    Filter: ((sentdate >= '2013-10-18 00:00:00-04'::timestamp with time zone) AND (sentdate < '2013-11-19 00:00:00-05'::timestamp with time zone))
              ->  Index Scan using "History_part_2013-10_transaction_id_idx" on "History_part_2013-10" "History"  (cost=0.00..9.87 rows=1 width=1884) (never executed)
                    Index Cond: ((transaction_id)::text = 'MMS-live-15425-2013-18-11-17:32:20.917198'::text)
                    Filter: ((sentdate >= '2013-10-18 00:00:00-04'::timestamp with time zone) AND (sentdate < '2013-11-19 00:00:00-05'::timestamp with time zone))
Total runtime: 0.572 ms

Seems like it is ALWAYS slow when running against 'main' History table (but not when calling partition directly) and only for the first time - is that some cashing thing? But then why calling partition directly is so much faster - calling main History table does not check all tables anymore.

share|improve this question
 
Isn't the fundamental issue that all partitions are checked? To profit of partition exlusion your partitioning criteria (sentdate) should be in the WHERE of the query. Can you add it to the query as additional field, maybe even by extracting it from transaction_id instead of adding it explicitly? –  C. Ramseyer Nov 12 at 22:00
 
BTW To minimize partitions, you should use it in both an upper and lower bound, e.g. select * from mms_history where transaction_id = 'x' and sentdate >= extractlowerboundsomehow(x) and sentdate <= extractupperboundsomehow(x). –  C. Ramseyer Nov 12 at 22:06
 
Among many things I did try following query as well: SELECT * FROM "History" WHERE transaction_id = 'MMS-dev-23599-2013-12-11-13:03:53.349735' AND sentdate<now() AND sentdate>now()-'1 month'::interval LIMIT 1 That was checking all tables. –  J. Raczkiewicz Nov 12 at 22:36
 
Also I wonder why second query runs so much faster, and why EXPLAIN ANALYZE after first query 'Total Runtime' so much smaller... Maybe automatic EXPLAIN ANALYZE executed after first query run speeds up the second one - help planer do the query right? I also did try to disable seqscan and tidscan for planner to force it to use indexes only (for a moment thought that first query does seq scan and then the following are doing index)... When I call the same query against specific partition it is fast so maybe you are right and the fundamental problem is that all partitions are scanned. –  J. Raczkiewicz Nov 12 at 22:43
1  
I think the problem may be the now()... "Constraint exclusion only works when the query's WHERE clause contains constants (or externally supplied parameters). For example, a comparison against a non-immutable function such as CURRENT_TIMESTAMP cannot be optimized, since the planner cannot know which partition the function value might fall into at run time." Caveats from postgresql.org/docs/9.3/static/…. Also check the constraint_exclusion is not disabled in config. –  C. Ramseyer Nov 12 at 22:44
show 2 more comments

1 Answer

up vote 0 down vote

See comments above, the partitioning criteria (sentdate) must be included in the query and must be a constant expression for partition exclusion to work.

share|improve this answer
add comment

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.