Opened 4 years ago

Closed 4 years ago

#4797 closed defect (wontfix)

Slow down on ST_DWithin upgrading from PostGis 2.5 to PostGis 3.0

Reported by: aelg Owned by: pramsey
Priority: medium Milestone: PostGIS 3.1.0
Component: postgis Version: 3.0.x
Keywords: Cc:

Description

Hello, We're using PostGis in production, currently Postgres9.6/PostGis 2.5 and wanted to upgrade to Postgres12/PostGis 3.0. But doing so we noticed a major slow down on requests which implies ST_DWithin, sometimes 1 sec on PG2.5 to 100sec on PG3.0. I can confirm now that it's not related to upgrading Postgres because I can reproduce slow requests with docker image postgis/postgis:12-3.0-alpine, but requests are fast on postgis/postgis:12-2.5-alpine.

Query is:

 SELECT "profile"."user_id" AS "profile_user_id" FROM "algorithmUser" "profile" LEFT JOIN "algorithmInteraction" "interaction" ON "interaction"."female_user_id"="profile"."user_id" AND ("interaction"."male_user_id" = '*AN_ID*') WHERE "profile"."gender" = 'FEMALE' AND "profile"."is_qualified_to_be_suggested" = true AND "profile"."birthdate" BETWEEN '1981-11-04' AND '2006-11-04' AND "profile"."last_activity_date" >'now'::timestamp - '2 month'::interval AND 
 ST_DWithin(
  ST_SetSRID(profile.location::geometry, 4326)::geography,
  ST_SetSRID(ST_MakePoint('2.346120595932007', '48.87633514404297'), 4326)::geography,
  '150000'
) AND ("interaction"."male_user_id" is NULL OR "interaction"."male_interaction_result" = 'NOT_INTERACTED') ORDER BY "profile"."last_activity_date" DESC LIMIT 30;

Here is a fast plane on PostGis2.5:

  Limit  (cost=32985.40..32985.41 rows=7 width=24) (actual time=1309.848..1310.630 rows=30 loops=1)
   ->  Sort  (cost=32985.40..32985.41 rows=7 width=24) (actual time=1309.830..1310.193 rows=30 loops=1)
         Sort Key: profile.last_activity_date DESC
         Sort Method: top-N heapsort  Memory: 29kB
         ->  Nested Loop Left Join  (cost=1000.00..32985.30 rows=7 width=24) (actual time=88.130..1304.894 rows=669 loops=1)
               Join Filter: (interaction.female_user_id = profile.user_id)
               Rows Removed by Join Filter: 88289
               Filter: ((interaction.male_user_id IS NULL) OR (interaction.male_interaction_result = 'NOT_INTERACTED'::"algorithmInteraction_male_interaction_result_enum"))
               Rows Removed by Filter: 93
               ->  Seq Scan on "algorithmUser" profile  (cost=0.00..6778.62 rows=34 width=24) (actual time=0.299..15.348 rows=762 loops=1)
                     Filter: (is_qualified_to_be_suggested AND (birthdate >= '1981-11-04'::date) AND (birthdate <= '2006-11-04'::date) AND (last_activity_date > '2020-09-19 17:41:18.3546'::timestamp without time zone) AND (gender = 'FEMALE'::"algorithmUser_gender_enum") AND ((st_setsrid((location)::geometry, 4326))::geography && '0101000020E6100000000000E0DAC40240000000C02B704840'::geography) AND ('0101000020E6100000000000E0DAC40240000000C02B704840'::geography && _st_expand((st_setsrid((location)::geometry, 4326))::geography, '150000'::double precision)) AND _st_dwithin((st_setsrid((location)::geometry, 4326))::geography, '0101000020E6100000000000E0DAC40240000000C02B704840'::geography, '150000'::double precision, true))
                     Rows Removed by Filter: 14830
               ->  Materialize  (cost=1000.00..26139.72 rows=113 width=36) (actual time=0.105..0.885 rows=116 loops=762)
                     ->  Gather  (cost=1000.00..26139.16 rows=113 width=36) (actual time=75.378..85.228 rows=116 loops=1)
                           Workers Planned: 2
                           Workers Launched: 2
                           ->  Parallel Seq Scan on "algorithmInteraction" interaction  (cost=0.00..25127.86 rows=47 width=36) (actual time=59.813..70.948 rows=39 loops=3)
                                 Filter: (male_user_id = '15fe5c41-d2a8-431e-ad4b-93134d301ecd'::uuid)
                                 Rows Removed by Filter: 326928
 Planning Time: 0.609 ms
 Execution Time: 1310.916 ms

And a slow one Postgis 3.0:

  Limit  (cost=444330.70..444330.71 rows=1 width=24) (actual time=102934.658..102938.991 rows=30 loops=1)
   ->  Sort  (cost=444330.70..444330.71 rows=1 width=24) (actual time=102917.048..102921.012 rows=30 loops=1)
         Sort Key: profile.last_activity_date DESC
         Sort Method: top-N heapsort  Memory: 29kB
         ->  Nested Loop Left Join  (cost=1000.00..444330.69 rows=1 width=24) (actual time=501.099..102912.441 rows=669 loops=1)
               Join Filter: (interaction.female_user_id = profile.user_id)
               Rows Removed by Join Filter: 88289
               Filter: ((interaction.male_user_id IS NULL) OR (interaction.male_interaction_result = 'NOT_INTERACTED'::"algorithmInteraction_male_interaction_result_enum"))
               Rows Removed by Filter: 93
               ->  Seq Scan on "algorithmUser" profile  (cost=0.00..420185.68 rows=1 width=24) (actual time=12.700..55.290 rows=762 loops=1)
                     Filter: (is_qualified_to_be_suggested AND (birthdate >= '1981-11-04'::date) AND (birthdate <= '2006-11-04'::date) AND (last_activity_date > '2020-09-19 17:43:53.189431'::timestamp without time zone) AND (gender = 'FEMALE'::"algorithmUser_gender_enum") AND st_dwithin((st_setsrid((location)::geometry, 4326))::geography, '0101000020E6100000000000E0DAC40240000000C02B704840'::geography, '150000'::double precision, true))
                     Rows Removed by Filter: 14830
               ->  Gather  (cost=1000.00..24104.47 rows=2703 width=36) (actual time=115.965..133.717 rows=116 loops=762)
                     Workers Planned: 2
                     Workers Launched: 2
                     ->  Parallel Seq Scan on "algorithmInteraction" interaction  (cost=0.00..22834.17 rows=1126 width=36) (actual time=55.030..67.398 rows=39 loops=2286)
                           Filter: (male_user_id = '15fe5c41-d2a8-431e-ad4b-93134d301ecd'::uuid)
                           Rows Removed by Filter: 326928
 Planning Time: 0.124 ms
 JIT:
   Functions: 20
   Options: Inlining false, Optimization false, Expressions true, Deforming true
   Timing: Generation 11.106 ms, Inlining 0.000 ms, Optimization 1.923 ms, Emission 38.001 ms, Total 51.030 ms
 Execution Time: 103113.558 ms

Would you see a work around we could use? Thanks, Aël

Change History (1)

comment:1 by pramsey, 4 years ago

Resolution: wontfix
Status: newclosed

The plans are almost exactly the same, and the performance drop happens in the nested loop left join, which doesn't even have a spatial clause. This points to some other, different, issue to me. If you can provide test data, and a query that demonstrates the difference, I can look at it, but otherwise there's nothing I can do.

Note: See TracTickets for help on using tickets.