Very slow response for a simple query, sometimes

Using Django Using the ORM
1

I have a fairly simple query that takes a long time – over 10 seconds – in some situations but not others. I’m not sure what’s up, or how to speed it up.

Models:

class Source(models.Model):
    feed_url = models.URLField(max_length=512)
    # Other fields describing a website with an RSS feed

class Post(models.Model):
    source = models.ForeignKey(Source, on_delete=models.CASCADE, related_name="posts")
    published_time = models.DateTimeField(db_index=True, null=True)
    # Other fields describing a single post on a website

If I do this in the shell:

source = Source.objects.get(pk=123)
first_post = source.posts.order_by("published_time").first()

then for some Sources it happens instantly. But for others, with similar numbers of Posts, it can take 10 or even 20 seconds!

That’s on the live server. But the same query, with the same slow Source, on my dev MacBook – but with a slightly older set of data – also happens instantly.

We’re talking around 1600 Posts for the Source, with a total number of Posts across all Sources of around 520,000.

This is the result of source.posts.order_by("published_time").explain():

Sort  (cost=5740.17..5744.23 rows=1625 width=700)
  Sort Key: published_time
  ->  Bitmap Heap Scan on feeds_post  (cost=25.02..5653.51 rows=1625 width=700)
        Recheck Cond: (source_id = '123'::smallint)
        ->  Bitmap Index Scan on feeds_post_source_id_3dffeb3b  (cost=0.00..24.61 rows=1625 width=0)
              Index Cond: (source_id = '123'::smallint)

I’m a bit stumped where to look next for what’s causing such a slowdown for a simple query, but only in some cases.

2

Is it always the same Source objects causing the slow queries? Or does the time vary even with the same source?

What is the shell output from:
print(source.posts.order_by("published_time").query)

What happens if you rewrite your query as:
Post.objects.filter(source_id=123).order_by('published_time').first()
Do you still see the same disparity of times?

You allow for null=True in your published_time field. Do the slow queries have a significant number where published_time is null? (What is the intended effect of published_time being null in your query?)

You mention a disparity of performance between two different platforms. Is the same database engine being used on each?
(What database is being used?)

3

Thanks for the questions Ken.

It appears to be certain Sources that always have these slow queries, while others are always fast.

I have noticed now that on the live server, even other sources are much slower than expected, like 5 seconds. I thought they were quicker earlier.

Linebreaks added for easier reading:

SELECT "feeds_post"."id","feeds_post"."source_id",
"feeds_post"."title", "feeds_post"."title_type",
"feeds_post"."title_language", "feeds_post"."body",
"feeds_post"."body_type", "feeds_post"."body_language",
"feeds_post"."link", "feeds_post"."imported_time", 
"feeds_post"."published_time", "feeds_post"."guid",
"feeds_post"."author", "feeds_post"."index",
"feeds_post"."word_count"
FROM "feeds_post"
WHERE "feeds_post"."source_id" = 1882
ORDER BY "feeds_post"."published_time" ASC

Yes.

No they have no NULL values for published_time. In theory none of the rows would have published_time as null, although I see that a dozen have slipped through.

It allows null because of an issue I had fetching RSS feeds, some of which don’t have a published time for each post, and so I then had to subsequently set the value after it was initially saved. It’s possible I could get round this another way if it would help.

Live server: psql (14.13 (Ubuntu 14.13-0ubuntu0.22.04.1))
MacBook Docker container: psql (14.4 (Debian 14.4-1.pgdg110+1))

And I’m on Django 5.1.1.

4

The problem may be that the number of objects is 520,000.

In my case, when the number of stored objects exceeded 200,000, db queries became slow.

Why call source.posts? It can be helpful to limit situations where you query a lot of data.

5

Well, I’m sad to say that I am completely unable to replicate anything close to what you’re describing here.

I created models based on what you’ve posted here, with the exception that I changed feed_url to a CharField.

I then created 2000 instances of Source each with 2000 instances of Post, creating 4,000,000 instances of Post total.

I then ran all sorts of queries, both using the ORM and directly in PSQL.

In all cases, execution time is < 10ms. (This is with me running the queries on the same system as the database. There is no network traffic involved.)

On my system, the combination of the two models and related indexes is < 400 MB, so unless you’re running in a really memory-constrained environment with a limited configuration, that shouldn’t be an issue. (This system is running with shared_buffers set to 4 GB, so once the cache is loaded, all these operations are probably all memory-resident.)

You could try a vacuum full, or reindex that model.

Is this a model being updated frequently?

You might try replicating that table to another table to see if there’s an internal organizational issue with the table.

It might also be worth trying to run your queries (and explaining them with the analyze parameter) to simply verify whether the issue is in Python / Django / psycopg2 or in the database itself.

I’m sorry I don’t have anything better for you here, I understand how frustrating these types of issues can be.

1 Like
6

Thanks Ken, I really appreciate the effort you’ve gone to! Sounds like you’re finding it similar to how I do on my local dev machine - plenty fast enough.

It does sound like it’s something specific to the server. I’ll get in touch with support - this is why I pay extra for it! - and let you know if I discover anything.

1 Like
7

I upgraded the VPS from 2GB RAM to 4GB RAM (which also increased the CPU cores from 1 to 2) and now the queries run almost instantly!

My host’s support person said this, which prompted me to upgrade:

I can’t see anything immediately wrong with the configuration, but the server was dipping into swap (causing the ‘iowait’ on the CPU usage graphs) as it’s got ~1.8 GB used of the 2GB the server has available, and the CPU load is occasionally being maxed out while its swapping.

So I guess there was just too much going on.

FWIW, there are three Django sites running on the VPS.

2 Likes
8

Yea, I don’t run any server / database combo (virtual or real) with less than 8 GB memory. (Aside from the SBC stuff running on Raspberry Pi - class systems, but that’s a completely different situation.)

Glad to see you have it resolved!

1 Like