public inbox for [email protected]  
help / color / mirror / Atom feed
Slow queries on simple index
10+ messages / 5 participants
[nested] [flat]

* Slow queries on simple index
@ 2026-01-17 13:58 Lillian Berry <[email protected]>
  2026-01-17 14:59 ` Re: Slow queries on simple index Pavel Stehule <[email protected]>
  2026-01-17 15:28 ` Re: Slow queries on simple index Ken Marshall <[email protected]>
  2026-01-17 16:57 ` Re: Slow queries on simple index Tom Lane <[email protected]>
  2026-01-17 20:21 ` Re: Slow queries on simple index Andrei Lepikhov <[email protected]>
  0 siblings, 4 replies; 10+ messages in thread

From: Lillian Berry @ 2026-01-17 13:58 UTC (permalink / raw)
  To: [email protected]; +Cc: [email protected]

Logs on our PostgreSQL cluster show frequent slow reads on a simple query by unique index. 

This issue has been present for some years, and survived multiple server moves as well as PostgreSQL version upgrades.
Vacuuming or reindexing the table does not seem to help.

Jan 17 13:38:13 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[172632]: pluralkit-db-dataLOG:  duration: 2322.842 ms  execute <unnamed>: SELECT * FROM "members" WHERE "hid" = $1
Jan 17 13:38:15 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[157893]: pluralkit-db-dataLOG:  duration: 2155.033 ms  execute _auto8: SELECT * FROM "members" WHERE "hid" = $1
Jan 17 13:38:16 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[157826]: pluralkit-db-dataLOG:  duration: 2164.851 ms  execute _auto10: SELECT * FROM "members" WHERE "hid" = $1
Jan 17 13:38:19 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[171076]: pluralkit-db-dataLOG:  duration: 2039.040 ms  execute _auto3: SELECT * FROM "members" WHERE "hid" = $1
Jan 17 13:38:20 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[162682]: pluralkit-db-dataLOG:  duration: 2189.700 ms  execute _auto8: SELECT * FROM "members" WHERE "hid" = $1
Jan 17 13:38:22 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[159824]: pluralkit-db-dataLOG:  duration: 2137.666 ms  execute _auto10: SELECT * FROM "members" WHERE "hid" = $1

Parameter detail has been redacted for privacy.

This is not reproducible on manual queries, whether using the same values or other random ones.

pluralkit=# explain (analyze, buffers, settings) select * from members where hid = 'exampl';
                                                          QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------
 Index Scan using members_hid_key on members  (cost=0.43..8.45 rows=1 width=838) (actual time=0.098..0.098 rows=0.00 loops=1)
   Index Cond: (hid = 'exampl'::bpchar)
   Index Searches: 1
   Buffers: shared hit=3
 Settings: effective_cache_size = '40GB'
 Planning Time: 0.161 ms
 Execution Time: 0.124 ms
(7 rows)

Table info:

pluralkit=# \d+ members
                                                                            Table "public.members"
         Column         |            Type             | Collation | Nullable |                 Default                  | Storage  | Compression | Stats target | Description
------------------------+-----------------------------+-----------+----------+------------------------------------------+----------+-------------+--------------+-------------
 id                     | integer                     |           | not null | nextval('members_id_seq'::regclass)      | plain    |             |              |
 hid                    | character(6)                |           | not null |                                          | extended |             |              |
 system                 | integer                     |           | not null | nextval('members_system_seq'::regclass)  | plain    |             |              |
 color                  | character(6)                |           |          |                                          | extended |             |              |
 avatar_url             | text                        |           |          |                                          | extended |             |              |
 name                   | text                        |           | not null |                                          | extended |             |              |
 birthday               | date                        |           |          |                                          | plain    |             |              |
 pronouns               | text                        |           |          |                                          | extended |             |              |
 description            | text                        |           |          |                                          | extended |             |              |
 created                | timestamp without time zone |           | not null | timezone('utc'::text, CURRENT_TIMESTAMP) | plain    |             |              |
 display_name           | text                        |           |          |                                          | extended |             |              |
 proxy_tags             | proxy_tag[]                 |           | not null | ARRAY[]::proxy_tag[]                     | extended |             |              |
 keep_proxy             | boolean                     |           | not null | false                                    | plain    |             |              |
 member_visibility      | integer                     |           | not null | 1                                        | plain    |             |              |
 message_count          | integer                     |           | not null | 0                                        | plain    |             |              |
 description_privacy    | integer                     |           | not null | 1                                        | plain    |             |              |
 name_privacy           | integer                     |           | not null | 1                                        | plain    |             |              |
 avatar_privacy         | integer                     |           | not null | 1                                        | plain    |             |              |
 birthday_privacy       | integer                     |           | not null | 1                                        | plain    |             |              |
 pronoun_privacy        | integer                     |           | not null | 1                                        | plain    |             |              |
 metadata_privacy       | integer                     |           | not null | 1                                        | plain    |             |              |
 allow_autoproxy        | boolean                     |           | not null | true                                     | plain    |             |              |
 banner_image           | text                        |           |          |                                          | extended |             |              |
 uuid                   | uuid                        |           |          | public.gen_random_uuid()                 | plain    |             |              |
 last_message_timestamp | timestamp without time zone |           |          |                                          | plain    |             |              |
 webhook_avatar_url     | text                        |           |          |                                          | extended |             |              |
 proxy_privacy          | integer                     |           | not null | 1                                        | plain    |             |              |
 tts                    | boolean                     |           | not null | false                                    | plain    |             |              |
 banner_privacy         | integer                     |           | not null | 1                                        | plain    |             |              |
Indexes:
    "members_pkey" PRIMARY KEY, btree (id)
    "members_by_system" btree (system)
    "members_hid_key" UNIQUE CONSTRAINT, btree (hid)
    "members_uuid_idx" btree (uuid)
Check constraints:
    "members_avatar_privacy_check" CHECK (avatar_privacy = ANY (ARRAY[1, 2]))
    "members_banner_privacy_check" CHECK (banner_privacy = ANY (ARRAY[1, 2]))
    "members_birthday_privacy_check" CHECK (birthday_privacy = ANY (ARRAY[1, 2]))
    "members_description_privacy_check" CHECK (description_privacy = ANY (ARRAY[1, 2]))
    "members_member_privacy_check" CHECK (member_visibility = ANY (ARRAY[1, 2]))
    "members_metadata_privacy_check" CHECK (metadata_privacy = ANY (ARRAY[1, 2]))
    "members_name_privacy_check" CHECK (name_privacy = ANY (ARRAY[1, 2]))
    "members_pronoun_privacy_check" CHECK (pronoun_privacy = ANY (ARRAY[1, 2]))
    "members_proxy_privacy_check" CHECK (proxy_privacy = ANY (ARRAY[1, 2]))
Foreign-key constraints:
    "members_system_fkey" FOREIGN KEY (system) REFERENCES systems(id) ON DELETE CASCADE
Referenced by:
    TABLE "autoproxy" CONSTRAINT "autoproxy_autoproxy_member_fkey" FOREIGN KEY (autoproxy_member) REFERENCES members(id) ON DELETE SET NULL
    TABLE "group_members" CONSTRAINT "group_members_member_id_fkey" FOREIGN KEY (member_id) REFERENCES members(id) ON DELETE CASCADE
    TABLE "member_guild" CONSTRAINT "member_guild_member_fkey" FOREIGN KEY (member) REFERENCES members(id) ON DELETE CASCADE
    TABLE "switch_members" CONSTRAINT "switch_members_member_fkey" FOREIGN KEY (member) REFERENCES members(id) ON DELETE CASCADE
Access method: heap

pluralkit=# SELECT relname, relpages, reltuples, relallvisible, relkind, relnatts, relhassubclass, reloptions, pg_table_size(oid) FROM pg_class WHERE relname='members';
-[ RECORD 1 ]--+--------------
relname        | members
relpages       | 816042
reltuples      | 1.3412575e+07
relallvisible  | 297904
relkind        | r
relnatts       | 29
relhassubclass | f
reloptions     |
pg_table_size  | 6687031296

postgresql.conf:

archive_command = '/nix/store/dz9vwg5grhvpz4v7rscdl95n7s5z8c3x-pluralkit-scripts-1/bin/pk-walg data 5432 pluralkit wal-push %p'
archive_mode = 'yes'
archive_timeout = 60
effective_cache_size = '40GB'
hba_file = '/nix/store/0pihm0qzk2pdn1d344p8kihpa58hd7s6-pg_hba.conf'
listen_addresses = 'localhost, 100.123.150.13, fdaa:9:e856:a7b:910f:0:a:102'
log_destination = 'stderr'
log_line_prefix = 'pluralkit-db-data'
log_min_duration_statement = 1000
max_connections = 2000
max_wal_size = '1GB'
min_wal_size = '80MB'
port = 5432
shared_buffers = '50GB'

Environment:

PostgreSQL 18.1 on x86_64-pc-linux-gnu, compiled by clang version 20.1.8, 64-bit
installed from nixpkgs
NixOS 25.11 on Linux 6.12.61 on AMD EPYC 7351P
2x Intel SSDPELKX020T7 in RAID1 (md-raid), with LUKS, ext4 filesystem

Same issue previously appeared on
PostgreSQL 14, both self-compiled and from nixpkgs
NixOS 24.10 on AMD Ryzen 7950X
ext4 filesystem directly on single Kioxia enterprise SSD (sorry I don't remember the model)

Kindly,
Lillian





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
@ 2026-01-17 14:59 ` Pavel Stehule <[email protected]>
  3 siblings, 0 replies; 10+ messages in thread

From: Pavel Stehule @ 2026-01-17 14:59 UTC (permalink / raw)
  To: Lillian Berry <[email protected]>; +Cc: [email protected]; [email protected]

Hi

so 17. 1. 2026 v 15:47 odesílatel Lillian Berry <[email protected]>
napsal:

> Logs on our PostgreSQL cluster show frequent slow reads on a simple query
> by unique index.
>
> This issue has been present for some years, and survived multiple server
> moves as well as PostgreSQL version upgrades.
> Vacuuming or reindexing the table does not seem to help.
>
> Jan 17 13:38:13 database-node1-bd9aa148
> pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[172632]:
> pluralkit-db-dataLOG:  duration: 2322.842 ms  execute <unnamed>: SELECT *
> FROM "members" WHERE "hid" = $1
> Jan 17 13:38:15 database-node1-bd9aa148
> pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[157893]:
> pluralkit-db-dataLOG:  duration: 2155.033 ms  execute _auto8: SELECT * FROM
> "members" WHERE "hid" = $1
> Jan 17 13:38:16 database-node1-bd9aa148
> pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[157826]:
> pluralkit-db-dataLOG:  duration: 2164.851 ms  execute _auto10: SELECT *
> FROM "members" WHERE "hid" = $1
> Jan 17 13:38:19 database-node1-bd9aa148
> pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[171076]:
> pluralkit-db-dataLOG:  duration: 2039.040 ms  execute _auto3: SELECT * FROM
> "members" WHERE "hid" = $1
> Jan 17 13:38:20 database-node1-bd9aa148
> pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[162682]:
> pluralkit-db-dataLOG:  duration: 2189.700 ms  execute _auto8: SELECT * FROM
> "members" WHERE "hid" = $1
> Jan 17 13:38:22 database-node1-bd9aa148
> pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[159824]:
> pluralkit-db-dataLOG:  duration: 2137.666 ms  execute _auto10: SELECT *
> FROM "members" WHERE "hid" = $1
>
> Parameter detail has been redacted for privacy.
>
> This is not reproducible on manual queries, whether using the same values
> or other random ones.e


There can be lot of possible reasons:

1. virtualization
2. network issues
3. application server lag
4. maybe by using transparent huge pages

It is pretty hard to identify these issues, because source of this issue
can be everything in every layer

At the end I executed every second just simple select SELECT 1; and I
checked the time

It can help with removing some hypotheses like application server issues or
network issues.

Regards

Pavel


> pluralkit=# explain (analyze, buffers, settings) select * from members
> where hid = 'exampl';
>                                                           QUERY PLAN
>
> ------------------------------------------------------------------------------------------------------------------------------
>  Index Scan using members_hid_key on members  (cost=0.43..8.45 rows=1
> width=838) (actual time=0.098..0.098 rows=0.00 loops=1)
>    Index Cond: (hid = 'exampl'::bpchar)
>    Index Searches: 1
>    Buffers: shared hit=3
>  Settings: effective_cache_size = '40GB'
>  Planning Time: 0.161 ms
>  Execution Time: 0.124 ms
> (7 rows)
>
> Table info:
>
> pluralkit=# \d+ members
>
>   Table "public.members"
>          Column         |            Type             | Collation |
> Nullable |                 Default                  | Storage  |
> Compression | Stats target | Description
>
> ------------------------+-----------------------------+-----------+----------+------------------------------------------+----------+-------------+--------------+-------------
>  id                     | integer                     |           | not
> null | nextval('members_id_seq'::regclass)      | plain    |             |
>             |
>  hid                    | character(6)                |           | not
> null |                                          | extended |             |
>             |
>  system                 | integer                     |           | not
> null | nextval('members_system_seq'::regclass)  | plain    |             |
>             |
>  color                  | character(6)                |           |
>   |                                          | extended |             |
>           |
>  avatar_url             | text                        |           |
>   |                                          | extended |             |
>           |
>  name                   | text                        |           | not
> null |                                          | extended |             |
>             |
>  birthday               | date                        |           |
>   |                                          | plain    |             |
>           |
>  pronouns               | text                        |           |
>   |                                          | extended |             |
>           |
>  description            | text                        |           |
>   |                                          | extended |             |
>           |
>  created                | timestamp without time zone |           | not
> null | timezone('utc'::text, CURRENT_TIMESTAMP) | plain    |             |
>             |
>  display_name           | text                        |           |
>   |                                          | extended |             |
>           |
>  proxy_tags             | proxy_tag[]                 |           | not
> null | ARRAY[]::proxy_tag[]                     | extended |             |
>             |
>  keep_proxy             | boolean                     |           | not
> null | false                                    | plain    |             |
>             |
>  member_visibility      | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  message_count          | integer                     |           | not
> null | 0                                        | plain    |             |
>             |
>  description_privacy    | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  name_privacy           | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  avatar_privacy         | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  birthday_privacy       | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  pronoun_privacy        | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  metadata_privacy       | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  allow_autoproxy        | boolean                     |           | not
> null | true                                     | plain    |             |
>             |
>  banner_image           | text                        |           |
>   |                                          | extended |             |
>           |
>  uuid                   | uuid                        |           |
>   | public.gen_random_uuid()                 | plain    |             |
>           |
>  last_message_timestamp | timestamp without time zone |           |
>   |                                          | plain    |             |
>           |
>  webhook_avatar_url     | text                        |           |
>   |                                          | extended |             |
>           |
>  proxy_privacy          | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
>  tts                    | boolean                     |           | not
> null | false                                    | plain    |             |
>             |
>  banner_privacy         | integer                     |           | not
> null | 1                                        | plain    |             |
>             |
> Indexes:
>     "members_pkey" PRIMARY KEY, btree (id)
>     "members_by_system" btree (system)
>     "members_hid_key" UNIQUE CONSTRAINT, btree (hid)
>     "members_uuid_idx" btree (uuid)
> Check constraints:
>     "members_avatar_privacy_check" CHECK (avatar_privacy = ANY (ARRAY[1,
> 2]))
>     "members_banner_privacy_check" CHECK (banner_privacy = ANY (ARRAY[1,
> 2]))
>     "members_birthday_privacy_check" CHECK (birthday_privacy = ANY
> (ARRAY[1, 2]))
>     "members_description_privacy_check" CHECK (description_privacy = ANY
> (ARRAY[1, 2]))
>     "members_member_privacy_check" CHECK (member_visibility = ANY
> (ARRAY[1, 2]))
>     "members_metadata_privacy_check" CHECK (metadata_privacy = ANY
> (ARRAY[1, 2]))
>     "members_name_privacy_check" CHECK (name_privacy = ANY (ARRAY[1, 2]))
>     "members_pronoun_privacy_check" CHECK (pronoun_privacy = ANY (ARRAY[1,
> 2]))
>     "members_proxy_privacy_check" CHECK (proxy_privacy = ANY (ARRAY[1, 2]))
> Foreign-key constraints:
>     "members_system_fkey" FOREIGN KEY (system) REFERENCES systems(id) ON
> DELETE CASCADE
> Referenced by:
>     TABLE "autoproxy" CONSTRAINT "autoproxy_autoproxy_member_fkey" FOREIGN
> KEY (autoproxy_member) REFERENCES members(id) ON DELETE SET NULL
>     TABLE "group_members" CONSTRAINT "group_members_member_id_fkey"
> FOREIGN KEY (member_id) REFERENCES members(id) ON DELETE CASCADE
>     TABLE "member_guild" CONSTRAINT "member_guild_member_fkey" FOREIGN KEY
> (member) REFERENCES members(id) ON DELETE CASCADE
>     TABLE "switch_members" CONSTRAINT "switch_members_member_fkey" FOREIGN
> KEY (member) REFERENCES members(id) ON DELETE CASCADE
> Access method: heap
>
> pluralkit=# SELECT relname, relpages, reltuples, relallvisible, relkind,
> relnatts, relhassubclass, reloptions, pg_table_size(oid) FROM pg_class
> WHERE relname='members';
> -[ RECORD 1 ]--+--------------
> relname        | members
> relpages       | 816042
> reltuples      | 1.3412575e+07
> relallvisible  | 297904
> relkind        | r
> relnatts       | 29
> relhassubclass | f
> reloptions     |
> pg_table_size  | 6687031296
>
> postgresql.conf:
>
> archive_command =
> '/nix/store/dz9vwg5grhvpz4v7rscdl95n7s5z8c3x-pluralkit-scripts-1/bin/pk-walg
> data 5432 pluralkit wal-push %p'
> archive_mode = 'yes'
> archive_timeout = 60
> effective_cache_size = '40GB'
> hba_file = '/nix/store/0pihm0qzk2pdn1d344p8kihpa58hd7s6-pg_hba.conf'
> listen_addresses = 'localhost, 100.123.150.13,
> fdaa:9:e856:a7b:910f:0:a:102'
> log_destination = 'stderr'
> log_line_prefix = 'pluralkit-db-data'
> log_min_duration_statement = 1000
> max_connections = 2000
> max_wal_size = '1GB'
> min_wal_size = '80MB'
> port = 5432
> shared_buffers = '50GB'
>
> Environment:
>
> PostgreSQL 18.1 on x86_64-pc-linux-gnu, compiled by clang version 20.1.8,
> 64-bit
> installed from nixpkgs
> NixOS 25.11 on Linux 6.12.61 on AMD EPYC 7351P
> 2x Intel SSDPELKX020T7 in RAID1 (md-raid), with LUKS, ext4 filesystem
>
> Same issue previously appeared on
> PostgreSQL 14, both self-compiled and from nixpkgs
> NixOS 24.10 on AMD Ryzen 7950X
> ext4 filesystem directly on single Kioxia enterprise SSD (sorry I don't
> remember the model)
>
> Kindly,
> Lillian
>
>
>


^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
@ 2026-01-17 15:28 ` Ken Marshall <[email protected]>
  2026-01-17 19:33   ` Re: Slow queries on simple index Lillian Berry <[email protected]>
  3 siblings, 1 reply; 10+ messages in thread

From: Ken Marshall @ 2026-01-17 15:28 UTC (permalink / raw)
  To: Lillian Berry <[email protected]>; +Cc: [email protected]; [email protected]

On Sat, Jan 17, 2026 at 02:58:01PM +0100, Lillian Berry wrote:
> Logs on our PostgreSQL cluster show frequent slow reads on a simple query by unique index. 
> 
> This issue has been present for some years, and survived multiple server moves as well as PostgreSQL version upgrades.
> Vacuuming or reindexing the table does not seem to help.
> 
> Jan 17 13:38:13 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[172632]: pluralkit-db-dataLOG:  duration: 2322.842 ms  execute <unnamed>: SELECT * FROM "members" WHERE "hid" = $1
> Jan 17 13:38:15 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[157893]: pluralkit-db-dataLOG:  duration: 2155.033 ms  execute _auto8: SELECT * FROM "members" WHERE "hid" = $1
> Jan 17 13:38:16 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[157826]: pluralkit-db-dataLOG:  duration: 2164.851 ms  execute _auto10: SELECT * FROM "members" WHERE "hid" = $1
> Jan 17 13:38:19 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[171076]: pluralkit-db-dataLOG:  duration: 2039.040 ms  execute _auto3: SELECT * FROM "members" WHERE "hid" = $1
> Jan 17 13:38:20 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[162682]: pluralkit-db-dataLOG:  duration: 2189.700 ms  execute _auto8: SELECT * FROM "members" WHERE "hid" = $1
> Jan 17 13:38:22 database-node1-bd9aa148 pzqzs8zyvqrq1rq25z4drws8dhnbxa59-run-postgres[159824]: pluralkit-db-dataLOG:  duration: 2137.666 ms  execute _auto10: SELECT * FROM "members" WHERE "hid" = $1
> 
> Parameter detail has been redacted for privacy.
> 
> This is not reproducible on manual queries, whether using the same values or other random ones.
> 

Hi,

You may want to try auto_explain to try and catch the explain for one of
these queries. You should also consider things like a checkpoint or
other query that needs a lot of I/O or needs a lock on the affected
table that would delay your query. I have had a system where the
statistics changed the query to a sequential scan instead of an index
lookup. Then when they stats were updated the query went back to the
index. This just looks like normal multi-body problem fluctuations which
can be identified by using much more instrumentation and logging at all
layers: network, disk, db logs,... Good luck.

Regards,
Ken





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-17 15:28 ` Re: Slow queries on simple index Ken Marshall <[email protected]>
@ 2026-01-17 19:33   ` Lillian Berry <[email protected]>
  0 siblings, 0 replies; 10+ messages in thread

From: Lillian Berry @ 2026-01-17 19:33 UTC (permalink / raw)
  To: Ken Marshall <[email protected]>; +Cc: [email protected]; [email protected]

Hi,

> You may want to try auto_explain to try and catch the explain for one of
> these queries.

I enabled auto_explain and it was very informative.

LOG:  duration: 2202.924 ms  execute <unnamed>: SELECT * FROM "members" WHERE "hid" = $1
LOG:  duration: 2202.918 ms  plan:
        Query Text: SELECT * FROM "members" WHERE "hid" = $1
        Query Parameters: $1 = '<redacted>'
        Gather  (cost=1000.00..907603.54 rows=67083 width=832) (actual time=1222.570..2202.893 rows=1.00 loops=1)
          Workers Planned: 2
          Workers Launched: 2
          Buffers: shared hit=816042
          ->  Parallel Seq Scan on members  (cost=0.00..899895.24 rows=27951 width=832) (actual time=1719.931..1972.703 rows=0.33 loops=3)
                Filter: ((hid)::text = '<redacted>'::text)
                Rows Removed by Filter: 4463227
                Buffers: shared hit=816042

It's not using the indexes at all.

Since the query is clearly the same as I attempted earlier, why would it not be using the index?

This table gets reasonably frequent inserts, but the insert timestamps don't really match up with the slow queries (for instance, there can be a 30-second gap where no rows are inserted, but there is still a slow query every few seconds). The table gets infrequent deletes.

Most if not all activity on this table is only updating single rows, or deleting based on the "system" foreign key column.
There is a job that calculates the count of rows (select count(*) from members), but it only runs once a minute and takes 1-2 seconds.

Kindly,
Lillian





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
@ 2026-01-17 16:57 ` Tom Lane <[email protected]>
  3 siblings, 0 replies; 10+ messages in thread

From: Tom Lane @ 2026-01-17 16:57 UTC (permalink / raw)
  To: Lillian Berry <[email protected]>; +Cc: [email protected]; [email protected]

"Lillian Berry" <[email protected]> writes:
> Logs on our PostgreSQL cluster show frequent slow reads on a simple query by unique index. 
> This issue has been present for some years, and survived multiple server moves as well as PostgreSQL version upgrades.
> Vacuuming or reindexing the table does not seem to help.

What else is going on in that database?  The fact that you show
several different sessions suffering similar delays at almost the
same time seems suspicious to me.  I'm wondering if something is
taking an exclusive lock on that table and then sitting on it
for a second or two.

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
@ 2026-01-17 20:21 ` Andrei Lepikhov <[email protected]>
  2026-01-17 20:52   ` Re: Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-17 21:10   ` Re: Slow queries on simple index Tom Lane <[email protected]>
  3 siblings, 2 replies; 10+ messages in thread

From: Andrei Lepikhov @ 2026-01-17 20:21 UTC (permalink / raw)
  To: Lillian Berry <[email protected]>; [email protected]; +Cc: [email protected]

On 17/1/26 14:58, Lillian Berry wrote:
> Logs on our PostgreSQL cluster show frequent slow reads on a simple query by unique index.
> 
> This issue has been present for some years, and survived multiple server moves as well as PostgreSQL version upgrades.
> Vacuuming or reindexing the table does not seem to help.
Hmm, where is the evidence that your query uses theindex? Maybe the 
generic plan accidentally forces SeqScan?

-- 
regards, Andrei Lepikhov,
pgEdge





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-17 20:21 ` Re: Slow queries on simple index Andrei Lepikhov <[email protected]>
@ 2026-01-17 20:52   ` Lillian Berry <[email protected]>
  1 sibling, 0 replies; 10+ messages in thread

From: Lillian Berry @ 2026-01-17 20:52 UTC (permalink / raw)
  To: Andrei Lepikhov <[email protected]>; [email protected]; +Cc: [email protected]

> Hmm, where is the evidence that your query uses theindex? Maybe the 
> generic plan accidentally forces SeqScan?

You may be correct - I just noticed that I am able to reproduce slow queries through my app. However, running the exact same queries in psql does use the index.

What might be different about my app's connections than psql? It uses Npgsql 9.0.2 on .NET 8, with these settings:

// src is "Host=[fdaa:9:e856:a7b:910f:0:a:102];Port=5432;Username=pluralkit;Database=pluralkit;Maximum Pool Size=150;Minimum Pool Size = 50;Max Auto Prepare=50"
var builder = new NpgsqlConnectionStringBuilder(src)
{
    Pooling = true,
    Enlist = false,
    NoResetOnClose = true,
    Timeout = 2
};

My understanding is slow query logs calculate the query time on the backend, and any client or network latency is not counted. Is this correct?

Kindly,
Lillian





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-17 20:21 ` Re: Slow queries on simple index Andrei Lepikhov <[email protected]>
@ 2026-01-17 21:10   ` Tom Lane <[email protected]>
  2026-01-17 22:06     ` [Solved] Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-18 09:24     ` Re: Slow queries on simple index Andrei Lepikhov <[email protected]>
  1 sibling, 2 replies; 10+ messages in thread

From: Tom Lane @ 2026-01-17 21:10 UTC (permalink / raw)
  To: Andrei Lepikhov <[email protected]>; +Cc: Lillian Berry <[email protected]>; [email protected]; [email protected]

Andrei Lepikhov <[email protected]> writes:
> Hmm, where is the evidence that your query uses theindex? Maybe the 
> generic plan accidentally forces SeqScan?

Oh ... you're on to something.  I think we all assumed that this was
an intermittent problem, but if it happens every time, I bet it's a
datatype mismatch issue.  Observe:

postgres=# create table members(hid char(6) unique not null);
CREATE TABLE
postgres=# prepare p as select * from members where hid = '42';
PREPARE
postgres=# explain execute p;
                                     QUERY PLAN                                      
-------------------------------------------------------------------------------------
 Index Only Scan using members_hid_key on members  (cost=0.15..8.17 rows=1 width=10)
   Index Cond: (hid = '42'::bpchar)
(2 rows)
postgres=# prepare p2(char) as select * from members where hid = $1;
PREPARE
postgres=# explain execute p2('42');
                                     QUERY PLAN                                      
-------------------------------------------------------------------------------------
 Index Only Scan using members_hid_key on members  (cost=0.15..8.17 rows=1 width=10)
   Index Cond: (hid = '42'::bpchar)
(2 rows)
postgres=# prepare p3(text) as select * from members where hid = $1;
PREPARE
postgres=# explain execute p3('42');
                        QUERY PLAN                        
----------------------------------------------------------
 Seq Scan on members  (cost=0.00..42.10 rows=11 width=10)
   Filter: ((hid)::text = '42'::text)
(2 rows)

If the $1 parameter is declared to be type "text" then it wins the
tug-of-war over which equals operator is used, and text-equals-text
does not match the bpchar index.

If it's not convenient to alter whatever aspect of the client logic is
causing that parameter to be marked as text, you could force the issue
by putting a cast into the text of the statement:

postgres=# prepare p4(text) as select * from members where hid = $1::char(6);
PREPARE
postgres=# explain execute p4('42');
                                     QUERY PLAN                                      
-------------------------------------------------------------------------------------
 Index Only Scan using members_hid_key on members  (cost=0.15..8.17 rows=1 width=10)
   Index Cond: (hid = '42    '::character(6))
(2 rows)

Or better yet, avoid using char(n).  It's a legacy type with no
real reason to exist, and it has semantic gotchas beyond this one.
varchar(n) is a much better idea.

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* [Solved] Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-17 20:21 ` Re: Slow queries on simple index Andrei Lepikhov <[email protected]>
  2026-01-17 21:10   ` Re: Slow queries on simple index Tom Lane <[email protected]>
@ 2026-01-17 22:06     ` Lillian Berry <[email protected]>
  1 sibling, 0 replies; 10+ messages in thread

From: Lillian Berry @ 2026-01-17 22:06 UTC (permalink / raw)
  To: Tom Lane <[email protected]>; Andrei Lepikhov <[email protected]>; +Cc: [email protected]; [email protected]

> I bet it's a datatype mismatch issue.

It was indeed!

I changed the query to `select * from members where hid = ($1)::char(6)` and this completely got rid of the slow queries.

Thanks all!

Kindly,
Lillian





^ permalink  raw  reply  [nested|flat] 10+ messages in thread

* Re: Slow queries on simple index
  2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
  2026-01-17 20:21 ` Re: Slow queries on simple index Andrei Lepikhov <[email protected]>
  2026-01-17 21:10   ` Re: Slow queries on simple index Tom Lane <[email protected]>
@ 2026-01-18 09:24     ` Andrei Lepikhov <[email protected]>
  1 sibling, 0 replies; 10+ messages in thread

From: Andrei Lepikhov @ 2026-01-18 09:24 UTC (permalink / raw)
  To: Tom Lane <[email protected]>; +Cc: Lillian Berry <[email protected]>; [email protected]; [email protected]

On 17/1/26 22:10, Tom Lane wrote:
> Andrei Lepikhov <[email protected]> writes:
>> Hmm, where is the evidence that your query uses theindex? Maybe the
>> generic plan accidentally forces SeqScan?
> 
> Oh ... you're on to something.  I think we all assumed that this was
> an intermittent problem, but if it happens every time, I bet it's a
> datatype mismatch issue.
Yes, index mismatches due to type differences are frequently a pain for 
me in the world of auto-generated queries. Why not spend a few 
additional cycles to check whether a potential cast is possible?
I didn't track what happened in this example, but it would be beneficial 
to let an extension implement such functionality. The prosupport 
machinery attached to an index looks like a promising approach.

-- 
regards, Andrei Lepikhov,
pgEdge





^ permalink  raw  reply  [nested|flat] 10+ messages in thread


end of thread, other threads:[~2026-01-18 09:24 UTC | newest]

Thread overview: 10+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2026-01-17 13:58 Slow queries on simple index Lillian Berry <[email protected]>
2026-01-17 14:59 ` Pavel Stehule <[email protected]>
2026-01-17 15:28 ` Ken Marshall <[email protected]>
2026-01-17 19:33   ` Lillian Berry <[email protected]>
2026-01-17 16:57 ` Tom Lane <[email protected]>
2026-01-17 20:21 ` Andrei Lepikhov <[email protected]>
2026-01-17 20:52   ` Lillian Berry <[email protected]>
2026-01-17 21:10   ` Tom Lane <[email protected]>
2026-01-17 22:06     ` Lillian Berry <[email protected]>
2026-01-18 09:24     ` Andrei Lepikhov <[email protected]>

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox