Date: Fri, 24 Oct 2025 13:19:03 +0200
From: hubert depesz lubaczewski <depesz@depesz.com>
Sender: depesz@depesz.com
To: PostgreSQL General <pgsql-general@lists.postgresql.org>
Subject: Re: Why is this query touching 4gb of buffers?
Message-ID: <aPtgp4xidEB_QA_H@depesz.com>
Reply-To: depesz@depesz.com
References: <aPtcnI2BZkeHjRvF@depesz.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: <aPtcnI2BZkeHjRvF@depesz.com>
Archived-At: <https://www.postgresql.org/message-id/aPtgp4xidEB_QA_H%40depesz.com>
Precedence: bulk

On Fri, Oct 24, 2025 at 01:01:48PM +0200, hubert depesz lubaczewski wrote:
> Hi,
> I have weird-ish case, that I can't grok, or at least explain in
> hand-wavy way.

A bit more info. Due to how the database is setup we have MANY "copies"
of the same table - same name, same columns, different schema, different
(but similar) data.

So, I tested the problem on another instance of this table. And there
was something really, really weird.

(this query has distinct on two columns, but it doesn't seem to be relevant, and tests whether having it, or not, showed not to generate any reasonable differences).

First run of the query generated:

                                                                                QUERY PLAN
══════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════
 HashAggregate  (cost=181382.51..181745.19 rows=36268 width=16) (actual time=27962.826..27962.826 rows=0 loops=1)
   Group Key: communication_channel_id, root_account_id
   Batches: 1  Memory Usage: 1561kB
   Buffers: shared hit=4624 read=117838 dirtied=486
   ->  Index Scan using index_some_table_pending on some_table  (cost=0.42..178322.57 rows=611988 width=16) (actual time=27962.567..27962.567 rows=0 loops=1)
         Index Cond: (send_at <= '2025-10-23 12:35:48'::timestamp without time zone)
         Buffers: shared hit=4624 read=117838 dirtied=486
 Planning:
   Buffers: shared hit=174
 Planning Time: 1.863 ms
 Execution Time: 27963.620 ms
(11 rows)

Then, immediately I reran it, without reindex, without analyze, without anything. And I got:

                                                                            QUERY PLAN
══════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════
 HashAggregate  (cost=181388.32..181751.00 rows=36268 width=16) (actual time=0.653..0.653 rows=0 loops=1)
   Group Key: communication_channel_id, root_account_id
   Batches: 1  Memory Usage: 1561kB
   Buffers: shared hit=424
   ->  Index Scan using index_some_table_pending on some_table  (cost=0.42..178328.27 rows=612009 width=16) (actual time=0.438..0.438 rows=0 loops=1)
         Index Cond: (send_at <= '2025-10-23 12:35:48'::timestamp without time zone)
         Buffers: shared hit=424
 Planning Time: 0.123 ms
 Execution Time: 1.237 ms
(9 rows)

Time is irrelevant, the point is that we are going down from ~120k buffers
"touched" to 424 buffers. What is going on?

I tested the same case on yet another setup, and ran simlar query
multiple times in a row on secondary, and got:
Buffers: shared hit=113849 read=198047 => Execution Time: 1359.661 ms
Buffers: shared hit=311896 => Execution Time: 246.143 ms

But when I ran the query on primary server tghere was very visiolble
change in buffers accesses:

Buffers: shared hit=114893 read=197776 dirtied=5528 => Execution Time: 75863.479 ms
Buffers: shared hit=775 => Execution Time: 2.360 ms

This didn't change buffers "touches" on secondary, though.

What am I missing?

Best regards,

depesz