0

I'm running an instance of Postgres 9.6.11 on AWS.

I have a few tables that aren't huge (one with a couple million records, one with a hundred thousand). I'm trying to query for the recommendation from one and match it up with the availability in another. For the most part my query seems to work pretty well, but when I switch out one variable for another in the recommendation table it takes it from a sub 1 second response time to a response time of over 8 seconds, despite there being as many rows returned for it (only about 25 total). This seems to consistently happen as I have tried it with a number of different variables and some of them just happen to be slow but most are fast.

I have tried this query:

SELECT A.item_id, availability.price, availability.company_id, availability.location_id, A.score
FROM (SELECT company_id, product_id, item_id, SUM(score) as score 
       FROM product_rec  
       WHERE company_id = '101' 
            AND product_id = '113' 
            AND category IN ('restroom') 
       GROUP BY company_id, product_id, item_id 
       HAVING COUNT(item_id) > 0 
       ORDER BY score DESC) AS A
JOIN availability 
   ON A.item_id = availability.item_id 
         AND A.company_id = availability.venue_id 
         AND A.product_id = availability.product_id
WHERE availability.item_id IN (A.item_id) 
      AND availability.company_id IN ('9802') 
      AND timestamp > CURRENT_TIMESTAMP - interval '1 hour'
GROUP BY A.item_id, availability.price, availability.company_id, availability.location_id, A.score
ORDER BY A.score DESC, A.item_id, availability.price, availability.company_id
LIMIT 100

If I have something like 'restroom' as the category it takes like 8 seconds, but if I do 'kitchen' or 'bedroom' it is sub < 1 second. Looking at just the subquery for each of them, they all return about the same number of results (less than 100). Is there something obvious I'm missing? If everything was the same and slow that would be a more obvious sign of a problem but I don't see why it would respond so differently to similar variables.

Any tips would be appreciated.

Updated to include Explain Analyze queries.

I'm pretty new to all of this, but it seems like for some reason the sorting is taking a lot of time. Am I reading that correctly?

First query:

QUERY PLAN
Limit  (cost=109295.15..109295.17 rows=1 width=46) (actual time=344.633..344.754 rows=100 loops=1)
->  Group  (cost=109295.15..109295.17 rows=1 width=46) (actual time=344.632..344.708 rows=100 loops=1)
        Group Key: a.score, a.item_id, availability.row_id, availability.location, availability.last_seat
->  Sort  (cost=109295.15..109295.16 rows=1 width=46) (actual time=344.630..344.655 rows=100 loops=1)
              Sort Key: a.score DESC, a.item_id, availability.row_id, availability.location, availability.last_seat
Sort Method: quicksort  Memory: 38kB
->  Nested Loop  (cost=182.98..109295.14 rows=1 width=46) (actual time=118.866..344.298 rows=177 loops=1)
Join Filter: ((a.item_id = availability.item_id) AND (a.company_id = availability.company_id) AND (a.product_id = availability.product_id))
Rows Removed by Join Filter: 20943
->  Seq Scan on availability  (cost=0.00..108859.78 rows=1802 width=22) (actual time=117.878..333.475 rows=880 loops=1)
                          Filter: ((event_id = 9802) AND ("timestamp" > (now() - '01:00:00'::interval)))
Rows Removed by Filter: 3285975
->  Materialize  (cost=182.98..183.10 rows=7 width=44) (actual time=0.001..0.006 rows=24 loops=880)
->  Subquery Scan on a  (cost=182.98..183.06 rows=7 width=44) (actual time=0.717..0.735 rows=24 loops=1)
->  Sort  (cost=182.98..182.99 rows=7 width=44) (actual time=0.716..0.723 rows=24 loops=1)
Sort Key: (sum(product_rec.score)) DESC
Sort Method: quicksort  Memory: 26kB
->  GroupAggregate  (cost=182.69..182.88 rows=7 width=44) (actual time=0.654..0.684 rows=24 loops=1)
                                            Group Key: product_rec.company_id, product_rec.product_id, product_rec.item_id
Filter: (count(product_rec.item_id) > 0)
->  Sort  (cost=182.69..182.70 rows=7 width=15) (actual time=0.636..0.641 rows=24 loops=1)
Sort Key: product_rec.item_id
Sort Method: quicksort  Memory: 26kB
->  Seq Scan on product_rec  (cost=0.00..182.59 rows=7 width=15) (actual time=0.498..0.595 rows=24 loops=1)
Filter: ((company_id = 101) AND (product_id = 113) AND (category = 'family'::text))
Rows Removed by Filter: 7381
Planning time: 0.296 ms
Execution time: 344.872 ms

Second query:

QUERY PLAN
Limit  (cost=109073.98..109073.99 rows=1 width=46) (actual time=5328.124..5328.246 rows=100 loops=1)
->  Group  (cost=109073.98..109073.99 rows=1 width=46) (actual time=5328.123..5328.200 rows=100 loops=1)
        Group Key: (sum(product_rec.score)), product_rec.item_id, availability.row_id, availability.location, availability.last_seat
->  Sort  (cost=109073.98..109073.98 rows=1 width=46) (actual time=5328.121..5328.146 rows=100 loops=1)
              Sort Key: (sum(product_rec.score)) DESC, product_rec.item_id, availability.row_id, availability.location, availability.last_seat
Sort Method: quicksort  Memory: 38kB
->  Nested Loop  (cost=182.64..109073.97 rows=1 width=46) (actual time=131.652..5327.588 rows=171 loops=1)
Join Filter: ((product_rec.item_id = availability.item_id) AND (product_rec.company_id = availability.company_id) AND (product_rec.product_id = availability.product_id))
Rows Removed by Join Filter: 13909
->  Sort  (cost=182.64..182.64 rows=1 width=44) (actual time=0.737..0.786 rows=16 loops=1)
Sort Key: (sum(product_rec.score)) DESC
Sort Method: quicksort  Memory: 26kB
->  GroupAggregate  (cost=182.60..182.63 rows=1 width=44) (actual time=0.701..0.718 rows=16 loops=1)
                                Group Key: product_rec.company_id, product_rec.product_id, product_rec.item_id
Filter: (count(product_rec.item_id) > 0)
->  Sort  (cost=182.60..182.60 rows=1 width=15) (actual time=0.685..0.691 rows=16 loops=1)
Sort Key: product_rec.item_id
Sort Method: quicksort  Memory: 26kB
->  Seq Scan on product_rec  (cost=0.00..182.59 rows=1 width=15) (actual time=0.568..0.656 rows=16 loops=1)
Filter: ((company_id = 101) AND (product_id = 113) AND (category = 'restroom'::text))
Rows Removed by Filter: 7389
->  Seq Scan on availability  (cost=0.00..108859.78 rows=1802 width=22) (actual time=117.995..332.699 rows=880 loops=16)
                          Filter: ((event_id = 9802) AND ("timestamp" > (now() - '01:00:00'::interval)))
Rows Removed by Filter: 3285975
Planning time: 0.613 ms
Execution time: 5328.374 ms

Update 2:

I should also note that removing the portion below seems to fix the problem, but I lose the ability to search for just specific categories. If there is an alternative idea of how to approach that, maybe it could solve this problem.

AND category IN ('restroom') 
  • Did you try to use EXPLAIN or EXPLAIN ANALYZE while trying to capture both the slow case and the fast case? That would help show if the plans are the same and the expected volume of the reply. – Patrick Mevzek Mar 28 at 19:21
  • Updated to include the EXPLAIN ANALYZE. Am I correct in reading that the sorting is the problem? – sforn Mar 28 at 20:00
  • Sorting takes next to no time at all. You might be interested in reading depesz.com/2013/04/16/explaining-the-unexplainable and the two later posts there. To visualize your plan, use explain.depesz.com - for example, your second plan: explain.depesz.com/s/OjpEO But note that the plan contains indentation for a reason. Please post them retaining whitespace, otherwise it is cumbersome to figure out what belong where (and the visualization also doesn't play nicely). – dezso Mar 29 at 8:22
  • Ok there is some sort of correlation between the number of loops it is performing and whatever I put in the category IN area. Any idea why it would vary from 1 to 26 loops on this? Doing that query by itself seems to results in a sub .1 query and they are all roughly the same amount of data coming back. It clearly happens with specific keywords only (they get consistent results)...but it doesn't appear to be alphabetical or anything like that. Interestingly combining several of the slower keywords in the IN statement ends up being much faster. – sforn Mar 29 at 20:18
  • @sforn thanks for providing your query plans, but without proper indentation they are not usable. – jjanes Mar 30 at 13:42

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.