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
