PostgreSQL first query slow

Question

I implemented cursor pagination. And for first rows it works realy well but the more I scroll down, the first query I send is slower. I run this query:

SELECT *
FROM "movie" "m"
INNER JOIN "movie_stats" "ms" ON "m"."uuid" = "ms"."movie_uuid"
WHERE (((("ms"."data"->'stat'->'overall'->>'total')::FLOAT), "ms"."movie_uuid") < (74.566, '50bca81c-4676-403e-8314-c721ba67646c')) AND ("m"."status" != 'deleted')

ORDER BY (("ms"."data"->'stat'->'overall'->>'total')::FLOAT) DESC NULLS LAST, "ms"."movie_uuid" DESC NULLS LAST
LIMIT 40

And after first run of query execution time is 444ms:

QUERY PLAN
Limit  (cost=0.84..154.18 rows=40 width=565) (actual time=9.171..444.788 rows=40 loops=1)"
  ->  Nested Loop  (cost=0.84..506620.20 rows=132160 width=565) (actual time=9.169..444.735 rows=40 loops=1)"
        ->  Index Scan using movie_stats_stat_overall_score_idx on movie_stats ""ms""  (cost=0.42..165910.17 rows=132443 width=741) (actual time=9.078..276.405 rows=40 loops=1)"
              Index Cond: (ROW(((((data -> 'stat'::text) -> 'overall'::text) ->> 'total'::text))::double precision, movie_uuid) < ROW('74.566'::double precision, '50bca81c-4676-403e-8314-c721ba67646c'::uuid))"
        ->  Index Scan using movie_pkey on movie m  (cost=0.42..2.56 rows=1 width=541) (actual time=4.188..4.188 rows=1 loops=40)"
              Index Cond: (uuid = ""ms"".movie_uuid)"
              Filter: (status <> 'deleted'::movie_status)"
Planning time: 1.140 ms
Execution time: 444.943 ms

But after executin this same query for second time exection time is only 1ms:

QUERY PLAN
Limit  (cost=0.84..154.18 rows=40 width=1314) (actual time=0.066..0.791 rows=40 loops=1)"
  ->  Nested Loop  (cost=0.84..506620.20 rows=132160 width=1314) (actual time=0.064..0.776 rows=40 loops=1)"
        ->  Index Scan using movie_stats_stat_overall_score_idx on movie_stats ""ms""  (cost=0.42..165910.17 rows=132443 width=749) (actual time=0.030..0.120 rows=40 loops=1)"
              Index Cond: (ROW(((((data -> 'col'::text) -> 'overall'::text) ->> 'total'::text))::double precision, movie_uuid) < ROW('74.566'::double precision, '50bca81c-4676-403e-8314-c721ba67646c'::uuid))"
        ->  Index Scan using movie_pkey on movie m  (cost=0.42..2.56 rows=1 width=541) (actual time=0.011..0.011 rows=1 loops=40)"
              Index Cond: (uuid = ""asc"".movie_uuid)"
              Filter: (status <> 'deleted'::movie_status)"
Planning time: 1.252 ms
Execution time: 0.916 ms

And this happens for each next 40 rows I go down. Can please someone explain me this. Thanks for help!

Answer 1

The first execution probably has to fetch data from disk, and the second already finds the data in shared buffers. You can diagnose that with EXPLAIN (ANALYZE, BUFFERS), which will show you the number of 8kB-blocks found in cache (hit) and read from disk (read).

For example:

 Seq Scan on tab  (...) (actual time=0.353..126.805 ...)
   Buffers: shared read=1959

versus

 Seq Scan on tab  (...) (actual time=0.011..21.471 ...)
   Buffers: shared hit=1959

If you need to speed that up, there are two possibilities:

1. Don't SELECT * and put all columns that you need in the query into the index. Then you can get an index-only scan, which may not hit the table at all if you VACUUM it.

   Of course, that is probably not feasible if you need a lot of columns.

2. Get more RAM and try to keep the table in cache. pg_prewarm may help.