On Thu, 29 May 2025 at 16:28, Fujii Masao <masao.fu...@oss.nttdata.com> wrote:
> I agree with changing the default value of auto_explain.log_buffers to true.
> I think that users who know EXPLAIN ANALYZE includes buffers info in
> the result by default since v18 would expect the buffer info also to
> be included in auto_explain output as long as log_analyze is enabled.
> So setting log_buffers to true by default would be less confusing.
I feel somewhat responsible to answer here since I committed the
EXPLAIN ANALYZE change. I'm still neutral.
By my count, those who think we should change log_buffers to true are:
Robert [1], Michael Christofides [2], Fujii [3].
I expect arguments against might be related to log space or
performance. I did a quick test to try to get an idea of what we're
looking at. I'm unsure how realistic it would be that someone would
use auto_explain to log this many plans, but there is a bit of a
performance overhead to enabling log_buffers. Full results attached,
but here's the summary after ignoring the first result of each and
taking the average of the remaining 9 runs of each. I deleted the log
file between each test.
log_min_duration = 0, log_buffers = off: 11231 tps
log_min_duration = 0, log_buffers = on: 11106 tps
log_min_duration = -1 (off): 13297 tps
So it is possible to measure it, at least.
David
[1]
https://www.postgresql.org/message-id/CA%2BTgmoZO2HtDGHf7K4rmNdfUGuS%3DngsPgwrH%3DJdyF6Okcnzfkw%40mail.gmail.com
[2]
https://www.postgresql.org/message-id/flat/a6206e08-0607-42fe-91fd-e7bd45fa235a%40oss.nttdata.com#47cd88d71be28287d3e29c833d98eb48
[3]
https://www.postgresql.org/message-id/a6206e08-0607-42fe-91fd-e7bd45fa235a%40oss.nttdata.com
# alter system set auto_explain.log_analyze = on;
ALTER SYSTEM
# alter system set auto_explain.log_min_duration=0;
ALTER SYSTEM
# alter system set auto_explain.log_timing=off;
ALTER SYSTEM
# select pg_reload_Conf();
pg_reload_conf
----------------
t
(1 row)
$ pgbench -i postgres
$ for i in {1..10}; do pgbench -n -M prepared -T 10 -S postgres | grep tps; done
tps = 11313.865802
tps = 11353.239133
tps = 11278.210905
tps = 11254.050329
tps = 11322.879711
tps = 11204.294425
tps = 11175.276264
tps = 11211.813427
tps = 11229.452802
tps = 11049.732047
# alter system set auto_explain.log_buffers=1;
ALTER SYSTEM
# select pg_reload_conf();
pg_reload_conf
----------------
t
(1 row)
$ for i in {1..10}; do pgbench -n -M prepared -T 10 -S postgres | grep tps; done
tps = 10509.378765
tps = 11077.139873
tps = 11232.809410
tps = 11141.543652
tps = 11003.065838
tps = 11121.254826
tps = 11136.912487
tps = 11039.627884
tps = 11079.197251
tps = 11122.450776
# alter system set auto_explain.log_min_duration=-1;
ALTER SYSTEM
# select pg_reload_conf();
pg_reload_conf
----------------
t
(1 row)
$ for i in {1..10}; do pgbench -n -M prepared -T 10 -S postgres | grep tps; done
tps = 12663.516909
tps = 13456.062885
tps = 13245.672977
tps = 13326.781348
tps = 13501.902909
tps = 13156.941863
tps = 13212.124942
tps = 13372.313995
tps = 13164.414056
tps = 13236.860009
