Re: Inconsistent query performance

I forgot to mention. I'm currently using postgres 8.3.x

On Apr 8, 2013, at 3:08 PM, Ramsey Gurley wrote:

> Hi all,
>
> I'm having issues with slow queries using postgres, and I'm finding some of the issues difficult to reproduce. My application logs slow queries for me, but often, when I go back to run explain analyze on the query it is very fast. I assume this is due to some sort of caching. Here is an example:
>
> sqlLogging _valuesForSQL ran 116509ms with sql string:
>
> select t1.transaction_id, t1.campaign_definition_id, t1.campaign_detail_number, t2.name as campaign_name, t1.communication_type, t1.delivery_error, t1.call_result into temporary activity_transactions_temp from customer.customer_transactions t1, campaign.campaign_definitions t2 where t1.customer_id = 2577 and t1.timestamp >= '04/08/2013' and t1.timestamp < '04/09/2013' and t1.campaign_definition_id = 23 and t1.campaign_definition_id = t2.campaign_definition_id order by campaign_name, communication_type;
>
> But if I run an explain analyze on that I get
>
> "Sort (cost=18.08..18.08 rows=1 width=89) (actual time=767.051..767.061 rows=17 loops=1)"
> " Sort Key: t2.name, t1.communication_type"
> " Sort Method: quicksort Memory: 26kB"
> " -> Nested Loop (cost=0.00..18.07 rows=1 width=89) (actual time=758.421..766.881 rows=17 loops=1)"
> " -> Index Scan using timestamp_only_ndx on customer_transactions t1 (cost=0.00..9.79 rows=1 width=69) (actual time=79.771..88.119 rows=17 loops=1)"
> " Index Cond: (("timestamp" >= '2013-04-08 00:00:00'::timestamp without time zone) AND ("timestamp" < '2013-04-09 00:00:00'::timestamp without time zone))"
> " Filter: ((customer_id = 2577) AND (campaign_definition_id = 23))"
> " -> Index Scan using campaign_definitions_campaign_definition_id_key on campaign_definitions t2 (cost=0.00..8.27 rows=1 width=24) (actual time=39.922..39.923 rows=1 loops=17)"
> " Index Cond: (t2.campaign_definition_id = 23)"
> "Total runtime: 770.830 ms"
>
> Is there anything that can tell me why this query took 117 seconds, and what, if anything, can be done to fix it?
>
> Here's another much more simple one:
>
> expression took 20147 ms:
>
> SELECT t0.appointment_id, t0.customer_id, t0.event_date, t0.patient_id, t0.transaction_id FROM customer.customer_transactions_detail t0 WHERE (t0.patient_id = 7441 AND t0.customer_id = 2965)
>
> "Index Scan using customer_id_patient_id_idx on customer_transactions_detail t0 (cost=0.00..10.22 rows=1 width=24) (actual time=35.952..99.487 rows=14 loops=1)"
> " Index Cond: ((customer_id = 2965) AND (patient_id = 7441))"
> "Total runtime: 99.537 ms"
>
> So it took 20 seconds at 12:18pm today, but now it takes ~100ms.
>
> Thanks,
>
> Ramsey