6

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 (!).

  • 1
    try running a VACUUM ANALYZE on your tables – JGH Mar 27 '18 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 '18 at 13:19
  • Where is this hosted? The two obvious questions (indexes and vacuuming) having been answered already. – John Powell Mar 27 '18 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 '18 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. – John Powell Mar 27 '18 at 17:26
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.

  • 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 '18 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 '18 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, privacy policy and cookie policy

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