PostgreSQL simple query slow on server

Question

I use Prisma for two really simple queries in my Node backend

const excavationSiteCount: number = (await client.excavation_sites.count({where: {owner: user}}));
const artifactCount: number = (await client.artifacts.count({where: {owner: user}}));

The response looks like this

{"Success":true,"Message":"Stats retrieved","Payload":{"Artifacts":0,"ExcavationSites":33,"SharedRecords":0}}

Normally nothing complex and these queries should be done quite quickly, if I test the whole thing locally, I get the following query runtimes in seconds

However If I measure the runtime on the server, I see the following:

That's really close to a second for these simple queries.

My VPS has the following specs:

Device name vmi2
Processor   Intel Core Processor (Broadwell, no TSX, IBRS)   2.20 GHz
Installed RAM   12.0 GB
System type 64-bit operating system, x64-based processor

I already adjusted shared_buffers, work_mem and effective_cache_size options, however this did not solve anything onfortunately.

So I'm curious what could be the problem here, has it maybe to do with prisma or something else?

The output from auto_explain:

2025-04-24 15:47:21 CEST LOG:  duration: 0.069 ms  plan:
    Query Text: select version()
    Result  (cost=0.00..0.01 rows=1 width=32) (actual time=0.040..0.041 rows=1 loops=1)
      Output: version()
2025-04-24 15:47:22 CEST LOG:  duration: 0.221 ms  plan:
    Query Text: select current_database() as a, current_schemas(false) as b
    Result  (cost=0.00..0.01 rows=1 width=96) (actual time=0.177..0.178 rows=1 loops=1)
      Output: current_database(), current_schemas(false)
      Buffers: shared hit=3
2025-04-24 15:47:22 CEST LOG:  duration: 0.217 ms  plan:
    Query Text: SELECT t.*
    FROM public.users t
    LIMIT 501
    Limit  (cost=0.00..1.02 rows=2 width=298) (actual time=0.206..0.208 rows=2 loops=1)
      Output: id, firstname, lastname
      Buffers: shared read=1
      ->  Seq Scan on public.users t  (cost=0.00..1.02 rows=2 width=298) (actual time=0.204..0.205 rows=2 loops=1)
            Output: id, firstname, lastname
            Buffers: shared read=1
2025-04-24 15:47:22 CEST LOG:  duration: 0.572 ms  plan:
    Query Text: SELECT c.oid, a.attnum, a.attname, c.relname, n.nspname, a.attnotnull OR (t.typtype = 'd' AND t.typnotnull), a.attidentity != '' OR pg_catalog.pg_get_expr(d.adbin, d.adrelid) LIKE '%nextval(%' FROM pg_catalog.pg_class c JOIN pg_catalog.pg_namespace n ON (c.relnamespace = n.oid) JOIN pg_catalog.pg_attribute a ON (c.oid = a.attrelid) JOIN pg_catalog.pg_type t ON (a.atttypid = t.oid) LEFT JOIN pg_catalog.pg_attrdef d ON (d.adrelid = a.attrelid AND d.adnum = a.attnum) JOIN (SELECT 16483 AS oid , 1 AS attnum UNION ALL SELECT 16483, 2 UNION ALL SELECT 16483, 3) vals ON (c.oid = vals.oid AND a.attnum = vals.attnum) 
    Nested Loop Left Join  (cost=0.91..24.15 rows=1 width=200) (actual time=0.238..0.534 rows=3 loops=1)
      Output: c.oid, a.attnum, a.attname, c.relname, n.nspname, (a.attnotnull OR ((t.typtype = 'd'::"char") AND t.typnotnull)), ((a.attidentity <> ''::"char") OR (pg_get_expr(d.adbin, d.adrelid) ~~ '%nextval(%'::text))
      Inner Unique: true
      Buffers: shared hit=41
      ->  Nested Loop  (cost=0.77..23.97 rows=1 width=206) (actual time=0.199..0.489 rows=3 loops=1)
            Output: c.oid, c.relname, n.nspname, a.attnum, a.attname, a.attnotnull, a.attidentity, a.attrelid, t.typtype, t.typnotnull
            Inner Unique: true
            Buffers: shared hit=38
            ->  Nested Loop  (cost=0.49..23.66 rows=1 width=208) (actual time=0.177..0.458 rows=3 loops=1)
                  Output: c.oid, c.relname, n.nspname, a.attnum, a.attname, a.attnotnull, a.attidentity, a.attrelid, a.atttypid
                  Inner Unique: true
                  Buffers: shared hit=29
                  ->  Nested Loop  (cost=0.36..23.46 rows=1 width=148) (actual time=0.162..0.436 rows=3 loops=1)
                        Output: c.oid, c.relname, c.relnamespace, a.attnum, a.attname, a.attnotnull, a.attidentity, a.attrelid, a.atttypid
                        Inner Unique: true
                        Join Filter: (a.attnum = (1))
                        Rows Removed by Join Filter: 21
                        Buffers: shared hit=23
                        ->  Hash Join  (cost=0.08..19.82 rows=3 width=80) (actual time=0.132..0.387 rows=3 loops=1)
                              Output: c.oid, c.relname, c.relnamespace, (16483), (1)
                              Hash Cond: (c.oid = ((16483))::oid)
                              Buffers: shared hit=14
                              ->  Seq Scan on pg_catalog.pg_class c  (cost=0.00..18.15 rows=415 width=72) (actual time=0.031..0.157 rows=480 loops=1)
                                    Output: c.oid, c.relname, c.relnamespace, c.reltype, c.reloftype, c.relowner, c.relam, c.relfilenode, c.reltablespace, c.relpages, c.reltuples, c.relallvisible, c.reltoastrelid, c.relhasindex, c.relisshared, c.relpersistence, c.relkind, c.relnatts, c.relchecks, c.relhasrules, c.relhastriggers, c.relhassubclass, c.relrowsecurity, c.relforcerowsecurity, c.relispopulated, c.relreplident, c.relispartition, c.relrewrite, c.relfrozenxid, c.relminmxid, c.relacl, c.reloptions, c.relpartbound
                                    Buffers: shared hit=14
                              ->  Hash  (cost=0.04..0.04 rows=3 width=8) (actual time=0.035..0.036 rows=3 loops=1)
                                    Output: (16483), (1)
                                    Buckets: 1024  Batches: 1  Memory Usage: 9kB
                                    ->  Append  (cost=0.00..0.04 rows=3 width=8) (actual time=0.011..0.014 rows=3 loops=1)
                                          ->  Result  (cost=0.00..0.01 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=1)
                                                Output: 16483, 1
                                          ->  Result  (cost=0.00..0.01 rows=1 width=8) (actual time=0.000..0.001 rows=1 loops=1)
                                                Output: 16483, 2
                                          ->  Result  (cost=0.00..0.01 rows=1 width=8) (actual time=0.000..0.001 rows=1 loops=1)
                                                Output: 16483, 3
                        ->  Index Scan using pg_attribute_relid_attnum_index on pg_catalog.pg_attribute a  (cost=0.28..1.11 rows=8 width=76) (actual time=0.009..0.012 rows=8 loops=3)
                              Output: a.attrelid, a.attname, a.atttypid, a.attlen, a.attnum, a.attcacheoff, a.atttypmod, a.attndims, a.attbyval, a.attalign, a.attstorage, a.attcompression, a.attnotnull, a.atthasdef, a.atthasmissing, a.attidentity, a.attgenerated, a.attisdropped, a.attislocal, a.attinhcount, a.attcollation, a.attstattarget, a.attacl, a.attoptions, a.attfdwoptions, a.attmissingval
                              Index Cond: (a.attrelid = c.oid)
                              Buffers: shared hit=9
                  ->  Index Scan using pg_namespace_oid_index on pg_catalog.pg_namespace n  (cost=0.13..0.18 rows=1 width=68) (actual time=0.006..0.006 rows=1 loops=3)
                        Output: n.oid, n.nspname, n.nspowner, n.nspacl
                        Index Cond: (n.oid = c.relnamespace)
                        Buffers: shared hit=6
            ->  Index Scan using pg_type_oid_index on pg_catalog.pg_type t  (cost=0.28..0.32 rows=1 width=6) (actual time=0.008..0.008 rows=1 loops=3)
                  Output: t.oid, t.typname, t.typnamespace, t.typowner, t.typlen, t.typbyval, t.typtype, t.typcategory, t.typispreferred, t.typisdefined, t.typdelim, t.typrelid, t.typsubscript, t.typelem, t.typarray, t.typinput, t.typoutput, t.typreceive, t.typsend, t.typmodin, t.typmodout, t.typanalyze, t.typalign, t.typstorage, t.typnotnull, t.typbasetype, t.typtypmod, t.typndims, t.typcollation, t.typdefaultbin, t.typdefault, t.typacl
                  Index Cond: (t.oid = a.atttypid)
                  Buffers: shared hit=9
      ->  Index Scan using pg_attrdef_adrelid_adnum_index on pg_catalog.pg_attrdef d  (cost=0.14..0.17 rows=1 width=38) (actual time=0.013..0.013 rows=0 loops=3)
            Output: d.oid, d.adrelid, d.adnum, d.adbin
            Index Cond: ((d.adrelid = a.attrelid) AND (d.adnum = a.attnum))
            Buffers: shared hit=3

The DDL of the queried table:

create table org_3077c8c7.users
(
    id        varchar(32) not null
        primary key,
    firstname varchar(45) not null,
    lastname  varchar(45) not null
);

Response time in DataGrip:

Then you'll have to do better profiling. Measure the time everywhere and see where it gets lost. On the database, use auto_explain. — Laurenz Albe, Commented 2 days ago
That's why I told you to use auto_explain, so that you get to see what really happens when the statements are executed. — Laurenz Albe, Commented 2 days ago
Ok, but at least you have excluded PostgreSQL as the source of your problem. — Laurenz Albe, Commented yesterday

Collectives™ on Stack Overflow

PostgreSQL simple query slow on server

0

Hot Network Questions

Collectives™ on Stack Overflow

0

Know someone who can answer? Share a link to this question via email, Twitter, or Facebook.