From 8026447a175a0c80ed4fc7e85550c07b3ab84834 Mon Sep 17 00:00:00 2001 From: Shinya Kato Date: Fri, 2 May 2025 10:28:50 +0900 Subject: [PATCH v1 2/2] Add log_autovacuum_analyze_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_vacuum_min_duration) and the threshold for log output of ANALYZE by autovacuum (log_autovacuum_analyze_min_duration). --- doc/src/sgml/config.sgml | 27 +++++++++++++++++++ doc/src/sgml/maintenance.sgml | 1 + doc/src/sgml/ref/create_table.sgml | 15 +++++++++++ src/backend/access/common/reloptions.c | 11 ++++++++ src/backend/commands/analyze.c | 8 +++--- src/backend/commands/vacuum.c | 6 ++++- src/backend/postmaster/autovacuum.c | 8 ++++++ src/backend/utils/misc/guc_tables.c | 12 +++++++++ src/backend/utils/misc/postgresql.conf.sample | 5 ++++ src/bin/psql/tab-complete.in.c | 2 ++ src/include/commands/vacuum.h | 3 +++ src/include/postmaster/autovacuum.h | 1 + src/include/utils/rel.h | 1 + .../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 + 18 files changed, 100 insertions(+), 5 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 1ae8dfd7137..e1544fcda73 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -7424,6 +7424,33 @@ local0.* /var/log/postgresql + + log_autovacuum_analyze_min_duration (integer) + + log_autovacuum_analyze_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. + + + + log_autovacuum_vacuum_min_duration (integer) diff --git a/doc/src/sgml/maintenance.sgml b/doc/src/sgml/maintenance.sgml index 84df5215580..066164a700a 100644 --- a/doc/src/sgml/maintenance.sgml +++ b/doc/src/sgml/maintenance.sgml @@ -889,6 +889,7 @@ 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. + 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 66954c66ba6..20a7909477e 100644 --- a/doc/src/sgml/ref/create_table.sgml +++ b/doc/src/sgml/ref/create_table.sgml @@ -1934,6 +1934,21 @@ WITH ( MODULUS numeric_literal, REM + + log_autovacuum_analyze_min_duration, toast.log_autovacuum_analyze_min_duration (integer) + + log_autovacuum_analyze_min_duration + storage parameter + + + + + Per-table value for + parameter. + + + + log_autovacuum_vacuum_min_duration, toast.log_autovacuum_vacuum_min_duration (integer) diff --git a/src/backend/access/common/reloptions.c b/src/backend/access/common/reloptions.c index 4bc618a34f0..f44d57556b6 100644 --- a/src/backend/access/common/reloptions.c +++ b/src/backend/access/common/reloptions.c @@ -319,6 +319,15 @@ static relopt_int intRelOpts[] = ShareUpdateExclusiveLock }, -1, 0, 2000000000 }, + { + { + "log_autovacuum_analyze_min_duration", + "Sets the minimum execution time above which analyze actions by autovacuum will be logged", + RELOPT_KIND_HEAP | RELOPT_KIND_TOAST, + ShareUpdateExclusiveLock + }, + -1, -1, INT_MAX + }, { { "log_autovacuum_vacuum_min_duration", @@ -1894,6 +1903,8 @@ default_reloptions(Datum reloptions, bool validate, relopt_kind kind) offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, multixact_freeze_max_age)}, {"autovacuum_multixact_freeze_table_age", RELOPT_TYPE_INT, offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, multixact_freeze_table_age)}, + {"log_autovacuum_analyze_min_duration", RELOPT_TYPE_INT, + offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, log_analyze_min_duration)}, {"log_autovacuum_vacuum_min_duration", RELOPT_TYPE_INT, offsetof(StdRdOptions, autovacuum) + offsetof(AutoVacOpts, log_vacuum_min_duration)}, {"toast_tuple_target", RELOPT_TYPE_INT, diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c index ba26b00cfb1..287ac50a71a 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_vacuum_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, VacuumParams *params, verbose = (params->options & VACOPT_VERBOSE) != 0; instrument = (verbose || (AmAutoVacuumWorkerProcess() && - params->log_vacuum_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, VacuumParams *params, { TimestampTz endtime = GetCurrentTimestamp(); - if (verbose || params->log_vacuum_min_duration == 0 || + if (verbose || params->log_analyze_min_duration == 0 || TimestampDifferenceExceeds(starttime, endtime, - params->log_vacuum_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 7e8d02d7a86..5494b58cb34 100644 --- a/src/backend/commands/vacuum.c +++ b/src/backend/commands/vacuum.c @@ -415,7 +415,11 @@ 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_vacuum_min_duration */ + /* + * user-invoked vacuum uses VACOPT_VERBOSE instead of + * log_analyze_min_duration and log_vacuum_min_duration + */ + params.log_analyze_min_duration = -1; params.log_vacuum_min_duration = -1; /* diff --git a/src/backend/postmaster/autovacuum.c b/src/backend/postmaster/autovacuum.c index cc77bbd8f11..498159eb46a 100644 --- a/src/backend/postmaster/autovacuum.c +++ b/src/backend/postmaster/autovacuum.c @@ -133,6 +133,7 @@ int autovacuum_multixact_freeze_max_age; double autovacuum_vac_cost_delay; int autovacuum_vac_cost_limit; +int Log_autovacuum_anl_min_duration = 600000; int Log_autovacuum_vac_min_duration = 600000; /* the minimum allowed time between two awakenings of the launcher */ @@ -2791,6 +2792,7 @@ 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_analyze_min_duration; int log_vacuum_min_duration; /* @@ -2800,6 +2802,11 @@ table_recheck_autovac(Oid relid, HTAB *table_toast_map, * defaults, autovacuum's own first and plain vacuum second. */ + /* -1 in autovac setting means use log_autovacuum_analyze_min_duration */ + log_analyze_min_duration = (avopts && avopts->log_analyze_min_duration >= 0) + ? avopts->log_analyze_min_duration + : Log_autovacuum_anl_min_duration; + /* -1 in autovac setting means use log_autovacuum_vacuum_min_duration */ log_vacuum_min_duration = (avopts && avopts->log_vacuum_min_duration >= 0) ? avopts->log_vacuum_min_duration @@ -2854,6 +2861,7 @@ 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_analyze_min_duration = log_analyze_min_duration; tab->at_params.log_vacuum_min_duration = log_vacuum_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 7ba26ebff5b..b74c7abebea 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -3168,6 +3168,18 @@ struct config_int ConfigureNamesInt[] = NULL, NULL, NULL }, + { + {"log_autovacuum_analyze_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_autovacuum_anl_min_duration, + 600000, -1, INT_MAX, + NULL, NULL, NULL + }, + { {"log_autovacuum_vacuum_min_duration", PGC_SIGHUP, LOGGING_WHAT, gettext_noop("Sets the minimum execution time above which " diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 90e02054acd..0f97ae1492e 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -585,6 +585,11 @@ #debug_print_rewritten = off #debug_print_plan = off #debug_pretty_print = on +#log_autovacuum_analyze_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 + # of milliseconds. #log_autovacuum_vacuum_min_duration = 10min # log vacuum activity by autovacuum; # -1 disables, 0 logs all actions and # their durations, > 0 logs only diff --git a/src/bin/psql/tab-complete.in.c b/src/bin/psql/tab-complete.in.c index 27f63159e43..8ddda6be2f8 100644 --- a/src/bin/psql/tab-complete.in.c +++ b/src/bin/psql/tab-complete.in.c @@ -1386,6 +1386,7 @@ static const char *const table_storage_parameters[] = { "autovacuum_vacuum_scale_factor", "autovacuum_vacuum_threshold", "fillfactor", + "log_autovacuum_analyze_min_duration", "log_autovacuum_vacuum_min_duration", "parallel_workers", "toast.autovacuum_enabled", @@ -1402,6 +1403,7 @@ static const char *const table_storage_parameters[] = { "toast.autovacuum_vacuum_max_threshold", "toast.autovacuum_vacuum_scale_factor", "toast.autovacuum_vacuum_threshold", + "toast.log_autovacuum_analyze_min_duration", "toast.log_autovacuum_vacuum_min_duration", "toast.vacuum_index_cleanup", "toast.vacuum_max_eager_freeze_failure_rate", diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h index 5a90b84e099..6c39deb722f 100644 --- a/src/include/commands/vacuum.h +++ b/src/include/commands/vacuum.h @@ -224,6 +224,9 @@ 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_analyze_min_duration; /* minimum execution threshold in ms + * at which analyze by 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 */ diff --git a/src/include/postmaster/autovacuum.h b/src/include/postmaster/autovacuum.h index 4d0b44a4f7a..59887c4d91f 100644 --- a/src/include/postmaster/autovacuum.h +++ b/src/include/postmaster/autovacuum.h @@ -47,6 +47,7 @@ extern PGDLLIMPORT int autovacuum_vac_cost_limit; /* autovacuum launcher PID, only valid when worker is shutting down */ extern PGDLLIMPORT int AutovacuumLauncherPid; +extern PGDLLIMPORT int Log_autovacuum_anl_min_duration; extern PGDLLIMPORT int Log_autovacuum_vac_min_duration; /* Status inquiry functions */ diff --git a/src/include/utils/rel.h b/src/include/utils/rel.h index 23e47af9112..b8810bedf90 100644 --- a/src/include/utils/rel.h +++ b/src/include/utils/rel.h @@ -322,6 +322,7 @@ typedef struct AutoVacOpts int multixact_freeze_min_age; int multixact_freeze_max_age; int multixact_freeze_table_age; + int log_analyze_min_duration; int log_vacuum_min_duration; float8 vacuum_cost_delay; float8 vacuum_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 9d64bee10eb..166c2fa571b 100644 --- a/src/test/modules/xid_wraparound/t/001_emergency_vacuum.pl +++ b/src/test/modules/xid_wraparound/t/001_emergency_vacuum.pl @@ -21,6 +21,7 @@ $node->append_conf( autovacuum_naptime = 1s # so it's easier to verify the order of operations autovacuum_max_workers = 1 +log_autovacuum_analyze_min_duration = 0 log_autovacuum_vacuum_min_duration = 0 ]); $node->start; diff --git a/src/test/modules/xid_wraparound/t/002_limits.pl b/src/test/modules/xid_wraparound/t/002_limits.pl index db87477ae5d..462791f3898 100644 --- a/src/test/modules/xid_wraparound/t/002_limits.pl +++ b/src/test/modules/xid_wraparound/t/002_limits.pl @@ -28,6 +28,7 @@ $node->init; $node->append_conf( 'postgresql.conf', qq[ autovacuum_naptime = 1s +log_autovacuum_analyze_min_duration = 0 log_autovacuum_vacuum_min_duration = 0 ]); $node->start; diff --git a/src/test/modules/xid_wraparound/t/003_wraparounds.pl b/src/test/modules/xid_wraparound/t/003_wraparounds.pl index 59c04a1d781..37769399c2c 100644 --- a/src/test/modules/xid_wraparound/t/003_wraparounds.pl +++ b/src/test/modules/xid_wraparound/t/003_wraparounds.pl @@ -24,6 +24,7 @@ $node->append_conf( autovacuum_naptime = 1s # so it's easier to verify the order of operations autovacuum_max_workers = 1 +log_autovacuum_analyze_min_duration = 0 log_autovacuum_vacuum_min_duration = 0 ]); $node->start; diff --git a/src/test/regress/pg_regress.c b/src/test/regress/pg_regress.c index e2001acd4aa..40de7a83b68 100644 --- a/src/test/regress/pg_regress.c +++ b/src/test/regress/pg_regress.c @@ -2400,6 +2400,7 @@ regression_main(int argc, char *argv[], bail("could not open \"%s\" for adding extra config: %m", buf); fputs("\n# Configuration added by pg_regress\n\n", pg_conf); + fputs("log_autovacuum_analyze_min_duration = 0\n", pg_conf); fputs("log_autovacuum_vacuum_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); diff --git a/src/tools/ci/pg_ci_base.conf b/src/tools/ci/pg_ci_base.conf index d9bb408aab4..1ff32e5c549 100644 --- a/src/tools/ci/pg_ci_base.conf +++ b/src/tools/ci/pg_ci_base.conf @@ -6,6 +6,7 @@ restart_after_crash = false max_prepared_transactions = 10 # Settings that make logs more useful +log_autovacuum_analyze_min_duration = 0 log_autovacuum_vacuum_min_duration = 0 log_checkpoints = true log_connections = all -- 2.39.3