[postgis-tickets] [PostGIS] #4797: Slow down on ST_DWithin upgrading from PostGis 2.5 to PostGis 3.0

PostGIS trac at osgeo.org
Fri Nov 20 08:55:18 PST 2020


#4797: Slow down on ST_DWithin upgrading from PostGis 2.5 to PostGis 3.0
---------------------+---------------------------
 Reporter:  aelg     |      Owner:  pramsey
     Type:  defect   |     Status:  new
 Priority:  medium   |  Milestone:  PostGIS 3.1.0
Component:  postgis  |    Version:  3.0.x
 Keywords:           |
---------------------+---------------------------
 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

-- 
Ticket URL: <https://trac.osgeo.org/postgis/ticket/4797>
PostGIS <http://trac.osgeo.org/postgis/>
The PostGIS Trac is used for bug, enhancement & task tracking, a user and developer wiki, and a view into the subversion code repository of PostGIS project.


More information about the postgis-tickets mailing list