buffers option ignored in aurora postgresql explain analyze command

Question

i've just realized that in Aurora PostgreSQL 13, the "buffers" option in explain is being ignored.

as you can see below, "Buffers: shared hit..." is missing from aurora postgresql result.

I'd like to ask any other way to get the buffer access information.

PostgreSQL RDS 12.7

metadb=> explain (analyze, buffers) select * from pg_tables where schemaname ='pg_catalog';
                                                        QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------
 Nested Loop Left Join  (cost=1.49..155.45 rows=20 width=260) (actual time=0.032..0.617 rows=63 loops=1)
   Join Filter: (t.oid = c.reltablespace)
   Rows Removed by Join Filter: 115
   Buffers: shared hit=119
   ->  Hash Join  (cost=1.49..153.88 rows=20 width=140) (actual time=0.025..0.577 rows=63 loops=1)
         Hash Cond: (c.relnamespace = n.oid)
         Buffers: shared hit=118
         ->  Seq Scan on pg_class c  (cost=0.00..150.20 rows=750 width=80) (actual time=0.009..0.503 rows=750 loops=1)
               Filter: (relkind = ANY ('{r,p}'::"char"[]))
               Rows Removed by Filter: 1906
               Buffers: shared hit=117
         ->  Hash  (cost=1.48..1.48 rows=1 width=68) (actual time=0.008..0.009 rows=1 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 9kB
               Buffers: shared hit=1
               ->  Seq Scan on pg_namespace n  (cost=0.00..1.48 rows=1 width=68) (actual time=0.005..0.006 rows=1 loops=1)
                     Filter: (nspname = 'pg_catalog'::name)
                     Rows Removed by Filter: 15
                     Buffers: shared hit=1
   ->  Materialize  (cost=0.00..1.03 rows=2 width=68) (actual time=0.000..0.000 rows=2 loops=63)
         Buffers: shared hit=1
         ->  Seq Scan on pg_tablespace t  (cost=0.00..1.02 rows=2 width=68) (actual time=0.002..0.002 rows=2 loops=1)
               Buffers: shared hit=1
 Planning Time: 0.242 ms
 Execution Time: 0.646 ms
(24 rows)

Time: 7.550 ms
metadb=> select version();
                                                 version
---------------------------------------------------------------------------------------------------------
 PostgreSQL 12.7 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-11), 64-bit
(1 row)

Time: 5.575 ms

PostgreSQL Aurora 13

metadb=> explain (analyze, buffers) select * from pg_tables where schemaname ='pg_catalog';
                                                        QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------
 Nested Loop Left Join  (cost=1.26..457.61 rows=117 width=260) (actual time=0.045..2.253 rows=62 loops=1)
   Join Filter: (t.oid = c.reltablespace)
   Rows Removed by Join Filter: 114
   ->  Hash Join  (cost=1.26..453.36 rows=117 width=140) (actual time=0.038..2.200 rows=62 loops=1)
         Hash Cond: (c.relnamespace = n.oid)
         ->  Seq Scan on pg_class c  (cost=0.00..444.68 rows=2331 width=80) (actual time=0.011..1.961 rows=2331 loops=1)
               Filter: (relkind = ANY ('{r,p}'::"char"[]))
               Rows Removed by Filter: 4843
         ->  Hash  (cost=1.25..1.25 rows=1 width=68) (actual time=0.010..0.011 rows=1 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 9kB
               ->  Seq Scan on pg_namespace n  (cost=0.00..1.25 rows=1 width=68) (actual time=0.005..0.007 rows=1 loops=1)
                     Filter: (nspname = 'pg_catalog'::name)
                     Rows Removed by Filter: 19
   ->  Materialize  (cost=0.00..1.03 rows=2 width=68) (actual time=0.000..0.000 rows=2 loops=62)
         ->  Seq Scan on pg_tablespace t  (cost=0.00..1.02 rows=2 width=68) (actual time=0.001..0.002 rows=2 loops=1)
 Planning Time: 0.287 ms
 Execution Time: 2.297 ms
(17 rows)

Time: 55.121 ms

update 1

I have tested 2 different method.

1. I create the RO instance in the same cluster

still no buffers info

metadb=> explain (analyze, buffers)select * from pg_tables;
                                                         QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
 Hash Left Join  (cost=2.49..479.51 rows=2331 width=260) (actual time=0.073..3.327 rows=2335 loops=1)
   Hash Cond: (c.reltablespace = t.oid)
   ->  Hash Left Join  (cost=1.45..453.55 rows=2331 width=140) (actual time=0.054..2.632 rows=2335 loops=1)
         Hash Cond: (c.relnamespace = n.oid)
         ->  Seq Scan on pg_class c  (cost=0.00..444.68 rows=2331 width=80) (actual time=0.010..2.064 rows=2335 loops=1)
               Filter: (relkind = ANY ('{r,p}'::"char"[]))
               Rows Removed by Filter: 4854
         ->  Hash  (cost=1.20..1.20 rows=20 width=68) (actual time=0.017..0.018 rows=20 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 10kB
               ->  Seq Scan on pg_namespace n  (cost=0.00..1.20 rows=20 width=68) (actual time=0.004..0.007 rows=20 loops=1)
   ->  Hash  (cost=1.02..1.02 rows=2 width=68) (actual time=0.003..0.004 rows=2 loops=1)
         Buckets: 1024  Batches: 1  Memory Usage: 9kB
         ->  Seq Scan on pg_tablespace t  (cost=0.00..1.02 rows=2 width=68) (actual time=0.001..0.002 rows=2 loops=1)
 Planning:
   I/O Timings: read=7.792
 Planning Time: 8.862 ms
 Execution Time: 3.516 ms
(17 rows)

2. cloned the cluster.

buffers info showed up.

metadb=> explain (analyze, buffers)select * from pg_tables;
                                                         QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
 Hash Left Join  (cost=2.49..479.51 rows=2331 width=260) (actual time=0.049..3.210 rows=2335 loops=1)
   Hash Cond: (c.reltablespace = t.oid)
   Buffers: shared hit=357
   ->  Hash Left Join  (cost=1.45..453.55 rows=2331 width=140) (actual time=0.041..2.563 rows=2335 loops=1)
         Hash Cond: (c.relnamespace = n.oid)
         Buffers: shared hit=356
         ->  Seq Scan on pg_class c  (cost=0.00..444.68 rows=2331 width=80) (actual time=0.010..1.996 rows=2335 loops=1)
               Filter: (relkind = ANY ('{r,p}'::"char"[]))
               Rows Removed by Filter: 4854
               Buffers: shared hit=355
         ->  Hash  (cost=1.20..1.20 rows=20 width=68) (actual time=0.019..0.020 rows=20 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 10kB
               Buffers: shared hit=1
               ->  Seq Scan on pg_namespace n  (cost=0.00..1.20 rows=20 width=68) (actual time=0.005..0.007 rows=20 loops=1)
                     Buffers: shared hit=1
   ->  Hash  (cost=1.02..1.02 rows=2 width=68) (actual time=0.004..0.004 rows=2 loops=1)
         Buckets: 1024  Batches: 1  Memory Usage: 9kB
         Buffers: shared hit=1
         ->  Seq Scan on pg_tablespace t  (cost=0.00..1.02 rows=2 width=68) (actual time=0.002..0.002 rows=2 loops=1)
               Buffers: shared hit=1
 Planning:
   Buffers: shared hit=16
 Planning Time: 0.262 ms
 Execution Time: 3.380 ms
(24 rows)

Still, cannot figure out what is causing this.

I've forwarded the same information to AWS. I'll update here when they provide me a solution to the problem.

Answer 1

it turned out to be an bug in aurora 13.4.0

After upgraded to aurora 13.4.2 version, buffers option is working.

however AWS calls aurora 13.4.x upgrade as minor upgrade.

I didn't even know there's aurora version until today.

you can check your aurora postgresql version by executing this sql below.

select aurora_version();