From 30242cf1e1c5e0c4481c86e1859a827a99e281a1 Mon Sep 17 00:00:00 2001 From: Shinya Kato Date: Mon, 23 Jun 2025 16:20:48 +0900 Subject: [PATCH v3] Add log_autoanalyze_min_duration The log output functionality of log_autovacuum_min_duration applies to both VACUUM and ANALYZE, so it is not possible to separate the VACUUM and ANALYZE log output thresholds. Logs are likely to be output only for VACUUM and not for ANALYZE. Therefore, we decided to separate the threshold for log output of VACUUM by autovacuum (log_autovacuum_min_duration) and the threshold for log output of ANALYZE by autovacuum (log_autoanalyze_min_duration). --- doc/src/sgml/config.sgml | 41 +++++++++++++++---- doc/src/sgml/maintenance.sgml | 3 +- doc/src/sgml/ref/create_table.sgml | 15 +++++++ src/backend/access/common/reloptions.c | 15 ++++++- src/backend/access/heap/vacuumlazy.c | 6 +-- src/backend/commands/analyze.c | 8 ++-- src/backend/commands/vacuum.c | 10 +++-- src/backend/postmaster/autovacuum.c | 16 ++++++-- src/backend/utils/misc/guc_tables.c | 18 +++++++- src/backend/utils/misc/postgresql.conf.sample | 7 +++- src/bin/psql/tab-complete.in.c | 2 + src/include/commands/vacuum.h | 9 ++-- src/include/postmaster/autovacuum.h | 1 + src/include/utils/rel.h | 3 +- .../xid_wraparound/t/001_emergency_vacuum.pl | 1 + .../modules/xid_wraparound/t/002_limits.pl | 1 + .../xid_wraparound/t/003_wraparounds.pl | 1 + src/test/regress/pg_regress.c | 1 + src/tools/ci/pg_ci_base.conf | 1 + 19 files changed, 128 insertions(+), 31 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 59a0874528a..add6ea9adbd 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -7435,17 +7435,44 @@ local0.* /var/log/postgresql - Causes each action executed by autovacuum to be logged if it ran for at + Causes vacuum action executed by autovacuum to be logged if it ran for at least the specified amount of time. Setting this to zero logs - all autovacuum actions. -1 disables logging autovacuum - actions. If this value is specified without units, it is taken as milliseconds. - For example, if you set this to - 250ms then all automatic vacuums and analyzes that run + all vacuum actions by autovacuum. -1 disables logging + vacuum actions by autovacuum. If this value is specified without units, + it is taken as milliseconds. For example, if you set this to + 250ms then all automatic vacuums that run 250ms or longer will be logged. In addition, when this parameter is set to any value other than -1, a message will be - logged if an autovacuum action is skipped due to a conflicting lock or a + logged if a vacuum action by autovacuum is skipped due to a conflicting lock or a concurrently dropped relation. The default is 10min. - Enabling this parameter can be helpful in tracking autovacuum activity. + Enabling this parameter can be helpful in tracking vacuum activity by autovacuum. + This parameter can only be set in the postgresql.conf + file or on the server command line; but the setting can be overridden for + individual tables by changing table storage parameters. + + + + + + log_autoanalyze_min_duration (integer) + + log_autoanalyze_min_duration + configuration parameter + + + + + Causes analyze action executed by autovacuum to be logged if it ran for at + least the specified amount of time. Setting this to zero logs + all analyze actions by autovacuum. -1 disables logging + analyze actions by autovacuum. If this value is specified without units, + it is taken as milliseconds. For example, if you set this to + 250ms then all automatic analyzes that run + 250ms or longer will be logged. In addition, when this parameter is + set to any value other than -1, a message will be + logged if an analyze action by autovacuum is skipped due to a conflicting lock or a + concurrently dropped relation. The default is 10min. + Enabling this parameter can be helpful in tracking analyze activity by autovacuum. This parameter can only be set in the postgresql.conf file or on the server command line; but the setting can be overridden for individual tables by changing table storage parameters. diff --git a/doc/src/sgml/maintenance.sgml b/doc/src/sgml/maintenance.sgml index e7a9f58c015..dc59c88319e 100644 --- a/doc/src/sgml/maintenance.sgml +++ b/doc/src/sgml/maintenance.sgml @@ -892,7 +892,8 @@ HINT: Execute a database-wide VACUUM in that database. the next database will be processed as soon as the first worker finishes. Each worker process will check each table within its database and execute VACUUM and/or ANALYZE as needed. - can be set to monitor + and + can be set to monitor autovacuum workers' activity. diff --git a/doc/src/sgml/ref/create_table.sgml b/doc/src/sgml/ref/create_table.sgml index dc000e913c1..9d59d00f1d4 100644 --- a/doc/src/sgml/ref/create_table.sgml +++ b/doc/src/sgml/ref/create_table.sgml @@ -1966,6 +1966,21 @@ WITH ( MODULUS numeric_literal, REM + + log_autoanalyze_min_duration, toast.log_autoanalyze_min_duration (integer) + + log_autoanalyze_min_duration + storage parameter + + + + + Per-table value for + parameter. + + + + vacuum_max_eager_freeze_failure_rate, toast.vacuum_max_eager_freeze_failure_rate (floating point) diff --git a/src/backend/access/common/reloptions.c b/src/backend/access/common/reloptions.c index 50747c16396..58fedc20e33 100644 --- a/src/backend/access/common/reloptions.c +++ b/src/backend/access/common/reloptions.c @@ -322,7 +322,16 @@ static relopt_int intRelOpts[] = { { "log_autovacuum_min_duration", - "Sets the minimum execution time above which autovacuum actions will be logged", + "Sets the minimum execution time above which vacuum actions by autovacuum will be logged", + RELOPT_KIND_HEAP | RELOPT_KIND_TOAST, + ShareUpdateExclusiveLock + }, + -1, -1, INT_MAX + }, + { + { + "log_autoanalyze_min_duration", + "Sets the minimum execution time above which analyze actions by autovacuum will be logged", RELOPT_KIND_HEAP | RELOPT_KIND_TOAST, ShareUpdateExclusiveLock }, @@ -1895,7 +1904,9 @@ default_reloptions(Datum reloptions, bool validate, relopt_kind kind) {"autovacuum_multixact_freeze_table_age", RELOPT_TYPE_INT, offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, multixact_freeze_table_age)}, {"log_autovacuum_min_duration", RELOPT_TYPE_INT, - offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, log_min_duration)}, + offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, log_vacuum_min_duration)}, + {"log_autoanalyze_min_duration", RELOPT_TYPE_INT, + offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, log_analyze_min_duration)}, {"toast_tuple_target", RELOPT_TYPE_INT, offsetof(StdRdOptions, toast_tuple_target)}, {"autovacuum_vacuum_cost_delay", RELOPT_TYPE_REAL, diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c index 75979530897..bd3c7ff2013 100644 --- a/src/backend/access/heap/vacuumlazy.c +++ b/src/backend/access/heap/vacuumlazy.c @@ -636,7 +636,7 @@ heap_vacuum_rel(Relation rel, const VacuumParams params, verbose = (params.options & VACOPT_VERBOSE) != 0; instrument = (verbose || (AmAutoVacuumWorkerProcess() && - params.log_min_duration >= 0)); + params.log_vacuum_min_duration >= 0)); if (instrument) { pg_rusage_init(&ru0); @@ -947,9 +947,9 @@ heap_vacuum_rel(Relation rel, const VacuumParams params, { TimestampTz endtime = GetCurrentTimestamp(); - if (verbose || params.log_min_duration == 0 || + if (verbose || params.log_vacuum_min_duration == 0 || TimestampDifferenceExceeds(starttime, endtime, - params.log_min_duration)) + params.log_vacuum_min_duration)) { long secs_dur; int usecs_dur; diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c index 7111d5d5334..ee0bb63b088 100644 --- a/src/backend/commands/analyze.c +++ b/src/backend/commands/analyze.c @@ -139,7 +139,7 @@ analyze_rel(Oid relid, RangeVar *relation, * Make sure to generate only logs for ANALYZE in this case. */ onerel = vacuum_open_relation(relid, relation, params.options & ~(VACOPT_VACUUM), - params.log_min_duration >= 0, + params.log_analyze_min_duration >= 0, ShareUpdateExclusiveLock); /* leave if relation could not be opened or locked */ @@ -311,7 +311,7 @@ do_analyze_rel(Relation onerel, const VacuumParams params, verbose = (params.options & VACOPT_VERBOSE) != 0; instrument = (verbose || (AmAutoVacuumWorkerProcess() && - params.log_min_duration >= 0)); + params.log_analyze_min_duration >= 0)); if (inh) ereport(elevel, (errmsg("analyzing \"%s.%s\" inheritance tree", @@ -736,9 +736,9 @@ do_analyze_rel(Relation onerel, const VacuumParams params, { TimestampTz endtime = GetCurrentTimestamp(); - if (verbose || params.log_min_duration == 0 || + if (verbose || params.log_analyze_min_duration == 0 || TimestampDifferenceExceeds(starttime, endtime, - params.log_min_duration)) + params.log_analyze_min_duration)) { long delay_in_ms; WalUsage walusage; diff --git a/src/backend/commands/vacuum.c b/src/backend/commands/vacuum.c index 733ef40ae7c..6694a705be7 100644 --- a/src/backend/commands/vacuum.c +++ b/src/backend/commands/vacuum.c @@ -416,8 +416,12 @@ ExecVacuum(ParseState *pstate, VacuumStmt *vacstmt, bool isTopLevel) /* user-invoked vacuum is never "for wraparound" */ params.is_wraparound = false; - /* user-invoked vacuum uses VACOPT_VERBOSE instead of log_min_duration */ - params.log_min_duration = -1; + /* + * user-invoked vacuum uses VACOPT_VERBOSE instead of + * log_vacuum_min_duration and log_analyze_min_duration + */ + params.log_vacuum_min_duration = -1; + params.log_analyze_min_duration = -1; /* * Later, in vacuum_rel(), we check if a reloption override was specified. @@ -2073,7 +2077,7 @@ vacuum_rel(Oid relid, RangeVar *relation, VacuumParams params, /* open the relation and get the appropriate lock on it */ rel = vacuum_open_relation(relid, relation, params.options, - params.log_min_duration >= 0, lmode); + params.log_vacuum_min_duration >= 0, lmode); /* leave if relation could not be opened or locked */ if (!rel) diff --git a/src/backend/postmaster/autovacuum.c b/src/backend/postmaster/autovacuum.c index 9474095f271..07bb320ff11 100644 --- a/src/backend/postmaster/autovacuum.c +++ b/src/backend/postmaster/autovacuum.c @@ -134,6 +134,7 @@ double autovacuum_vac_cost_delay; int autovacuum_vac_cost_limit; int Log_autovacuum_min_duration = 600000; +int Log_autoanalyze_min_duration = 600000; /* the minimum allowed time between two awakenings of the launcher */ #define MIN_AUTOVAC_SLEEPTIME 100.0 /* milliseconds */ @@ -2791,7 +2792,8 @@ table_recheck_autovac(Oid relid, HTAB *table_toast_map, int freeze_table_age; int multixact_freeze_min_age; int multixact_freeze_table_age; - int log_min_duration; + int log_vacuum_min_duration; + int log_analyze_min_duration; /* * Calculate the vacuum cost parameters and the freeze ages. If there @@ -2801,10 +2803,15 @@ table_recheck_autovac(Oid relid, HTAB *table_toast_map, */ /* -1 in autovac setting means use log_autovacuum_min_duration */ - log_min_duration = (avopts && avopts->log_min_duration >= 0) - ? avopts->log_min_duration + log_vacuum_min_duration = (avopts && avopts->log_vacuum_min_duration >= 0) + ? avopts->log_vacuum_min_duration : Log_autovacuum_min_duration; + /* -1 in autovac setting means use log_autoanalyze_min_duration */ + log_analyze_min_duration = (avopts && avopts->log_analyze_min_duration >= 0) + ? avopts->log_analyze_min_duration + : Log_autoanalyze_min_duration; + /* these do not have autovacuum-specific settings */ freeze_min_age = (avopts && avopts->freeze_min_age >= 0) ? avopts->freeze_min_age @@ -2854,7 +2861,8 @@ table_recheck_autovac(Oid relid, HTAB *table_toast_map, tab->at_params.multixact_freeze_min_age = multixact_freeze_min_age; tab->at_params.multixact_freeze_table_age = multixact_freeze_table_age; tab->at_params.is_wraparound = wraparound; - tab->at_params.log_min_duration = log_min_duration; + tab->at_params.log_vacuum_min_duration = log_vacuum_min_duration; + tab->at_params.log_analyze_min_duration = log_analyze_min_duration; tab->at_params.toast_parent = InvalidOid; /* diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index 511dc32d519..11fbd48c331 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -3171,8 +3171,9 @@ struct config_int ConfigureNamesInt[] = { {"log_autovacuum_min_duration", PGC_SIGHUP, LOGGING_WHAT, gettext_noop("Sets the minimum execution time above which " - "autovacuum actions will be logged."), - gettext_noop("-1 disables logging autovacuum actions. 0 means log all autovacuum actions."), + "vacuum actions by autovacuum will be logged."), + gettext_noop("-1 disables logging vacuum actions by autovacuum. " + "0 means log all vacuum actions by autovacuum."), GUC_UNIT_MS }, &Log_autovacuum_min_duration, @@ -3180,6 +3181,19 @@ struct config_int ConfigureNamesInt[] = NULL, NULL, NULL }, + { + {"log_autoanalyze_min_duration", PGC_SIGHUP, LOGGING_WHAT, + gettext_noop("Sets the minimum execution time above which " + "analyze actions by autovacuum will be logged."), + gettext_noop("-1 disables logging analyze actions by autovacuum. " + "0 means log all analyze actions by autovacuum."), + GUC_UNIT_MS + }, + &Log_autoanalyze_min_duration, + 600000, -1, INT_MAX, + NULL, NULL, NULL + }, + { {"log_parameter_max_length", PGC_SUSET, LOGGING_WHAT, gettext_noop("Sets the maximum length in bytes of data logged for bind " diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 341f88adc87..d2ed29230ce 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -585,7 +585,12 @@ #debug_print_rewritten = off #debug_print_plan = off #debug_pretty_print = on -#log_autovacuum_min_duration = 10min # log autovacuum activity; +#log_autovacuum_min_duration = 10min # log vacuum activity by autovacuum; + # -1 disables, 0 logs all actions and + # their durations, > 0 logs only + # actions running at least this number + # of milliseconds. +#log_autoanalyze_min_duration = 10min # log analyze activity by autovacuum; # -1 disables, 0 logs all actions and # their durations, > 0 logs only # actions running at least this number diff --git a/src/bin/psql/tab-complete.in.c b/src/bin/psql/tab-complete.in.c index 8c2ea0b9587..154540a03e8 100644 --- a/src/bin/psql/tab-complete.in.c +++ b/src/bin/psql/tab-complete.in.c @@ -1395,6 +1395,7 @@ static const char *const table_storage_parameters[] = { "autovacuum_vacuum_threshold", "fillfactor", "log_autovacuum_min_duration", + "log_autoanalyze_min_duration", "parallel_workers", "toast.autovacuum_enabled", "toast.autovacuum_freeze_max_age", @@ -1411,6 +1412,7 @@ static const char *const table_storage_parameters[] = { "toast.autovacuum_vacuum_scale_factor", "toast.autovacuum_vacuum_threshold", "toast.log_autovacuum_min_duration", + "toast.log_autoanalyze_min_duration", "toast.vacuum_index_cleanup", "toast.vacuum_max_eager_freeze_failure_rate", "toast.vacuum_truncate", diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h index 14eeccbd718..7b9b29e673f 100644 --- a/src/include/commands/vacuum.h +++ b/src/include/commands/vacuum.h @@ -224,9 +224,12 @@ typedef struct VacuumParams int multixact_freeze_table_age; /* multixact age at which to scan * whole table */ bool is_wraparound; /* force a for-wraparound vacuum */ - int log_min_duration; /* minimum execution threshold in ms at - * which autovacuum is logged, -1 to use - * default */ + int log_vacuum_min_duration; /* minimum execution threshold in ms + * at which vacuum by autovacuum is + * logged, -1 to use default */ + int log_analyze_min_duration; /* minimum execution threshold in ms + * at which analyze by autovacuum is + * logged, -1 to use default */ VacOptValue index_cleanup; /* Do index vacuum and cleanup */ VacOptValue truncate; /* Truncate empty pages at the end */ Oid toast_parent; /* for privilege checks when recursing */ diff --git a/src/include/postmaster/autovacuum.h b/src/include/postmaster/autovacuum.h index e8135f41a1c..023ac6d5fa8 100644 --- a/src/include/postmaster/autovacuum.h +++ b/src/include/postmaster/autovacuum.h @@ -48,6 +48,7 @@ extern PGDLLIMPORT int autovacuum_vac_cost_limit; extern PGDLLIMPORT int AutovacuumLauncherPid; extern PGDLLIMPORT int Log_autovacuum_min_duration; +extern PGDLLIMPORT int Log_autoanalyze_min_duration; /* Status inquiry functions */ extern bool AutoVacuumingActive(void); diff --git a/src/include/utils/rel.h b/src/include/utils/rel.h index b552359915f..e63aa31d151 100644 --- a/src/include/utils/rel.h +++ b/src/include/utils/rel.h @@ -322,7 +322,8 @@ typedef struct AutoVacOpts int multixact_freeze_min_age; int multixact_freeze_max_age; int multixact_freeze_table_age; - int log_min_duration; + int log_vacuum_min_duration; + int log_analyze_min_duration; float8 vacuum_cost_delay; float8 vacuum_scale_factor; float8 vacuum_ins_scale_factor; diff --git a/src/test/modules/xid_wraparound/t/001_emergency_vacuum.pl b/src/test/modules/xid_wraparound/t/001_emergency_vacuum.pl index 73d1ec4af19..59870956631 100644 --- a/src/test/modules/xid_wraparound/t/001_emergency_vacuum.pl +++ b/src/test/modules/xid_wraparound/t/001_emergency_vacuum.pl @@ -22,6 +22,7 @@ autovacuum_naptime = 1s # so it's easier to verify the order of operations autovacuum_max_workers = 1 log_autovacuum_min_duration = 0 +log_autoanalyze_min_duration = 0 ]); $node->start; $node->safe_psql('postgres', 'CREATE EXTENSION xid_wraparound'); diff --git a/src/test/modules/xid_wraparound/t/002_limits.pl b/src/test/modules/xid_wraparound/t/002_limits.pl index aa1d8765d3a..05bafa12d98 100644 --- a/src/test/modules/xid_wraparound/t/002_limits.pl +++ b/src/test/modules/xid_wraparound/t/002_limits.pl @@ -29,6 +29,7 @@ $node->append_conf( 'postgresql.conf', qq[ autovacuum_naptime = 1s log_autovacuum_min_duration = 0 +log_autoanalyze_min_duration = 0 ]); $node->start; $node->safe_psql('postgres', 'CREATE EXTENSION xid_wraparound'); diff --git a/src/test/modules/xid_wraparound/t/003_wraparounds.pl b/src/test/modules/xid_wraparound/t/003_wraparounds.pl index 2aeaee8769c..083191de06e 100644 --- a/src/test/modules/xid_wraparound/t/003_wraparounds.pl +++ b/src/test/modules/xid_wraparound/t/003_wraparounds.pl @@ -25,6 +25,7 @@ autovacuum_naptime = 1s # so it's easier to verify the order of operations autovacuum_max_workers = 1 log_autovacuum_min_duration = 0 +log_autoanalyze_min_duration = 0 ]); $node->start; $node->safe_psql('postgres', 'CREATE EXTENSION xid_wraparound'); diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index 5d85dcc62f0..399f1634a1c 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -2401,6 +2401,7 @@ regression_main(int argc, char *argv[], fputs("\n# Configuration added by pg_regress\n\n", pg_conf); fputs("log_autovacuum_min_duration = 0\n", pg_conf); + fputs("log_autoanalyze_min_duration = 0\n", pg_conf); fputs("log_checkpoints = on\n", pg_conf); fputs("log_line_prefix = '%m %b[%p] %q%a '\n", pg_conf); fputs("log_lock_waits = on\n", pg_conf); diff --git a/src/tools/ci/pg_ci_base.conf b/src/tools/ci/pg_ci_base.conf index 695e0a0d6ec..ff05646c90e 100644 --- a/src/tools/ci/pg_ci_base.conf +++ b/src/tools/ci/pg_ci_base.conf @@ -7,6 +7,7 @@ max_prepared_transactions = 10 # Settings that make logs more useful log_autovacuum_min_duration = 0 +log_autoanalyze_min_duration = 0 log_checkpoints = true log_connections = all log_disconnections = true -- 2.39.3