7

One of my websites suddenly got much slower, and I've managed to track down the issue to a query that uses the <-> operator together with ORDER BY (2D distance between two geometries) to retrieve the 10 rows with a POINT field nearest a geographic point. The strange thing is that the exact same query has been working fine for a long time.

The app had been responding within 400 ms for the 99 percentile (and with an average of about 100 ms) up until a few days ago when the 99 percentile suddenly went up to over 1000 ms. Here's a graph of this:

Web Response Times

Turning on logging of slow SQL queries (>250 ms), the following query comes up repeatedly:

LOG:  duration: 1084.692 ms  statement:
SELECT
    event.*, place.slug as place_slug, place.published as place_published, place.id as place_id, place.name as place_name
FROM
    event
INNER JOIN
    place
ON
    event.city_id=place.original_id
WHERE
    deleted=false AND
    is_public=true
ORDER BY
    point <-> st_setsrid(st_makepoint(103.856757191,1.29607891905),4326) LIMIT 10

It's a very common query in my app, so it should explain why the response time rocketed. An EXPLAIN on the query gives:

                                                   QUERY PLAN
----------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.83..15445.04 rows=10 width=1875)
   ->  Nested Loop  (cost=0.83..2478796.59 rows=1605 width=1875)
         ->  Index Scan using event_point_id on event  (cost=0.41..2462008.83 rows=6835 width=1849)
               Order By: (point <-> '0101000020E61000005FE7DE77975D5E4025CC3F39943D3F40'::geometry)
               Filter: ((NOT deleted) AND is_public)
         ->  Index Scan using place_original_id on place  (cost=0.42..2.45 rows=1 width=30)
               Index Cond: (original_id = event.city_id)
(7 rows)

There's been no dramatic size change of the database table though it's continually growing slowly so I'm guessing it might have climbed over some threshold.

What might have caused the query to suddenly become much slower, and what steps I can take to debug it?

PostgreSQL version is 9.4.

Update with some more clues:

I realized that when I remove the deleted=false condition in the WHERE clause, the query suddenly execute fast again. It's only 439,000 rows, out of 1,505,000 rows that have deleted set to true. However 178,000 of these rows got updated with deleted set to true at around the time when the query suddenly became slow (!).

7
  • 1
    try running a VACUUM ANALYZE on your tables
    – JGH
    Mar 27, 2018 at 13:02
  • I ran VACUUM ANALYZE on the tables but unfortunately it had no effect. (Also, I do have the autovacuum daemon running).
    – heyman
    Mar 27, 2018 at 13:19
  • Where is this hosted? The two obvious questions (indexes and vacuuming) having been answered already. Mar 27, 2018 at 15:18
  • @JohnPowellakaBarça It's hosted on a dedicated server. Server load is fine, and there were no spike in traffic when the slow down happened.
    – heyman
    Mar 27, 2018 at 16:08
  • Has the spike now gone? Vacuuming can lead to horrible performance if it kicks in after many updates. It sounds unlikely in your case, as it sounds like constant load. I run very heavy updates on a couple of DBs every few weeks - - millions of inserts, updstes and deletes - - and the post processing vacuum renders the DB essentially unusable. This is done offline, obviously. Mar 27, 2018 at 17:26

2 Answers 2

1

Around version 9.5 (approximately) there were a change in the <->, &&, etc operators. Before that, they reported distance between bounding boxes, now they report true feature distance. The latter is more accurate though slower.

All this makes little sense with points, but the change also seems to have effected the use of spatial indexes ('using gist' indexes on the geom field) so you might see it too.

I suggest you consider if your DB have been upgraded. In any case make sure you have spatial indexes in the relevant fields. Also you may be able to twist the setup to return to the old behavior, which can make sense if you work with points only.

2
  • Unfortunately, that's not the problem for me. This app is still on 9.4 (which I realize that I should have written in the question). Also, there were no index changes when it happened. The only change that I can think of is that the size grew over some threshold which caused the slowdown.
    – heyman
    Mar 28, 2018 at 9:11
  • I made some findings which I believe could be great clues to what might be wrong for someone with a deeper understanding of PostGIS indexes than me. I've added them to the bottom of the question.
    – heyman
    Mar 29, 2018 at 10:43
0

I've now managed to find out what the issue was. The problem didn't have anything to do with the spatial index, or the geometry distance query, which was what I initially thought.

Because of another, unrelated issue event.city_id had been set to null for a majority of all the rows. Changing the INNER JOIN to a LEFT JOIN made the query fast again..

Since the query used an INNER JOIN, I'm guessing that Postgres had to scan a very large portion of the table when so few of the rows actually had city_id set. The reason the query got fast when I removed the deleted=false condition was because the rows that had deleted set to true had not gotten their city_id set to null.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.