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).

Author: Shinya Kato <shinya11.kato@gmail.com>
Reviewed-by: Kasahara Tatsuhito <kasaharatt@oss.nttdata.com>
Discussion: https://www.postgresql.org/message-id/flat/CAOzEurQtfV4MxJiWT-XDnimEeZAY+rgzVSLe8YsyEKhZcajzSA@mail.gmail.com

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 39e658b7808be56f34ec42a05a696dd91863d18a..0a2a8b49fdba5749881dc0c8e6ad812aafaa780b 100644 (file)
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7477,17 +7477,44 @@ local0.*    /var/log/postgresql
       </term>
       <listitem>
        <para>
-        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. <literal>-1</literal> disables logging autovacuum
-        actions. If this value is specified without units, it is taken as milliseconds.
-        For example, if you set this to
-        <literal>250ms</literal> then all automatic vacuums and analyzes that run
+        all vacuum actions by autovacuum. <literal>-1</literal> 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
+        <literal>250ms</literal> then all automatic vacuums that run
         250ms or longer will be logged.  In addition, when this parameter is
         set to any value other than <literal>-1</literal>, 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 <literal>10min</literal>.
-        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 <filename>postgresql.conf</filename>
+        file or on the server command line; but the setting can be overridden for
+        individual tables by changing table storage parameters.
+       </para>
+      </listitem>
+     </varlistentry>
+
+     <varlistentry id="guc-log-autoanalyze-min-duration" xreflabel="log_autoanalyze_min_duration">
+      <term><varname>log_autoanalyze_min_duration</varname> (<type>integer</type>)
+      <indexterm>
+       <primary><varname>log_autoanalyze_min_duration</varname></primary>
+       <secondary>configuration parameter</secondary>
+      </indexterm>
+      </term>
+      <listitem>
+       <para>
+        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. <literal>-1</literal> 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
+        <literal>250ms</literal> then all automatic analyzes that run
+        250ms or longer will be logged.  In addition, when this parameter is
+        set to any value other than <literal>-1</literal>, 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 <literal>10min</literal>.
+        Enabling this parameter can be helpful in tracking analyze activity by autovacuum.
         This parameter can only be set in the <filename>postgresql.conf</filename>
         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 e7a9f58c01582b343de5cc598aea4e51ef3f9081..dc59c88319ebce53749f53ea8bd673ae7a19ff11 100644 (file)
--- 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 <command>VACUUM</command> and/or <command>ANALYZE</command> as needed.
-    <xref linkend="guc-log-autovacuum-min-duration"/> can be set to monitor
+    <xref linkend="guc-log-autovacuum-min-duration"/> and
+    <xref linkend="guc-log-autoanalyze-min-duration"/> can be set to monitor
     autovacuum workers' activity.
    </para>
 

diff --git a/doc/src/sgml/ref/create_table.sgml b/doc/src/sgml/ref/create_table.sgml
index dc000e913c1439691c17270b05b9610dbfb4ede7..a157a244e4ef2b8050106f43099ce005e3e127c2 100644 (file)
--- a/doc/src/sgml/ref/create_table.sgml
+++ b/doc/src/sgml/ref/create_table.sgml
@@ -1966,6 +1966,21 @@ WITH ( MODULUS <replaceable class="parameter">numeric_literal</replaceable>, REM
     </listitem>
    </varlistentry>
 
+   <varlistentry id="reloption-log-autoanalyze-min-duration" xreflabel="log_autoanalyze_min_duration">
+    <term><literal>log_autoanalyze_min_duration</literal> (<type>integer</type>)
+    <indexterm>
+     <primary><varname>log_autoanalyze_min_duration</varname></primary>
+     <secondary>storage parameter</secondary>
+    </indexterm>
+    </term>
+    <listitem>
+     <para>
+      Per-table value for <xref linkend="guc-log-autoanalyze-min-duration"/>
+      parameter.
+     </para>
+    </listitem>
+   </varlistentry>
+
    <varlistentry id="reloption-vacuum-max-eager-freeze-failure-rate" xreflabel="vacuum_max_eager_freeze_failure_rate">
     <term><literal>vacuum_max_eager_freeze_failure_rate</literal>, <literal>toast.vacuum_max_eager_freeze_failure_rate</literal> (<type>floating point</type>)
     <indexterm>

diff --git a/src/backend/access/common/reloptions.c b/src/backend/access/common/reloptions.c
index 35150bf237bce283998bf1ddbf71f86188b17f7d..9e288dfecbfd01876b616ab0387b06c7f5031169 100644 (file)
--- a/src/backend/access/common/reloptions.c
+++ b/src/backend/access/common/reloptions.c
@@ -322,12 +322,21 @@ 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,
+                       ShareUpdateExclusiveLock
+               },
+               -1, -1, INT_MAX
+       },
        {
                {
                        "toast_tuple_target",
@@ -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 71fbd68c8eaeb91b8418a0a4b1154daea680d3e3..d2b031fdd06ba2feea04c39e6a85aa8ec5d832ab 100644 (file)
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -648,7 +648,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);
@@ -959,9 +959,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 12b4f3fd36ead9bf353a6c780cd08e37f945ad9a..c2e216563c63c1e0cd5385c3398d06c33e2be65e 100644 (file)
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -138,7 +138,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 */
@@ -310,7 +310,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",
@@ -735,9 +735,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 e2f181eed7b8246a19d7ca6ccfeb77a3529f88d1..ed03e3bd50d83accd3183be4c9d386e0bea6e71f 100644 (file)
--- a/src/backend/commands/vacuum.c
+++ b/src/backend/commands/vacuum.c
@@ -406,8 +406,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.
@@ -2063,7 +2067,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 fb5d3b27224d2cc4b16f4f9157ab7d88c5464040..5084af7dfb66e5ecc93d8fb945560272096bea20 100644 (file)
--- a/src/backend/postmaster/autovacuum.c
+++ b/src/backend/postmaster/autovacuum.c
@@ -133,6 +133,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 */
@@ -2814,7 +2815,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
@@ -2824,10 +2826,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
@@ -2877,7 +2884,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_parameters.dat b/src/backend/utils/misc/guc_parameters.dat
index b176d5130e4908020b08bf05b07cc53f44954e99..d6fc833385057d6ecc7d714c12412e301e847a50 100644 (file)
--- a/src/backend/utils/misc/guc_parameters.dat
+++ b/src/backend/utils/misc/guc_parameters.dat
@@ -1771,8 +1771,8 @@
 },
 
 { name => 'log_autovacuum_min_duration', type => 'int', context => 'PGC_SIGHUP', group => 'LOGGING_WHAT',
-  short_desc => 'Sets the minimum execution time above which autovacuum actions will be logged.',
-  long_desc => '-1 disables logging autovacuum actions. 0 means log all autovacuum actions.',
+  short_desc => 'Sets the minimum execution time above which vacuum actions by autovacuum will be logged.',
+  long_desc => '-1 disables logging vacuum actions by autovacuum. 0 means log all vacuum actions by autovacuum.',
   flags => 'GUC_UNIT_MS',
   variable => 'Log_autovacuum_min_duration',
   boot_val => '600000',
@@ -1780,6 +1780,16 @@
   max => 'INT_MAX',
 },
 
+{ name => 'log_autoanalyze_min_duration', type => 'int', context => 'PGC_SIGHUP', group => 'LOGGING_WHAT',
+  short_desc => 'Sets the minimum execution time above which analyze actions by autovacuum will be logged.',
+  long_desc => '-1 disables logging analyze actions by autovacuum. 0 means log all analyze actions by autovacuum.',
+  flags => 'GUC_UNIT_MS',
+  variable => 'Log_autoanalyze_min_duration',
+  boot_val => '600000',
+  min => '-1',
+  max => 'INT_MAX',
+},
+
 { name => 'log_parameter_max_length', type => 'int', context => 'PGC_SUSET', group => 'LOGGING_WHAT',
   short_desc => 'Sets the maximum length in bytes of data logged for bind parameter values when logging statements.',
   long_desc => '-1 means log values in full.',

diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index c5d612ab552635322b34a9d49a3f24d81c3fda6b..f62b61967ef6fc5bc7be6e5ecb978280e191083e 100644 (file)
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -588,7 +588,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 64bfd309c9a18e5d4edf568d6d6a5d5472f57337..ad37f9f6ed0daf98e2ce3bd03a7706c1ade4bbf8 100644 (file)
--- a/src/bin/psql/tab-complete.in.c
+++ b/src/bin/psql/tab-complete.in.c
@@ -1421,6 +1421,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",

diff --git a/src/include/commands/vacuum.h b/src/include/commands/vacuum.h
index 14eeccbd71850c394554159f1c1b9392ab26bda8..1f3290c7fbfb434c0d84ce3021fffc0010cc6f96 100644 (file)
--- a/src/include/commands/vacuum.h
+++ b/src/include/commands/vacuum.h
@@ -224,9 +224,14 @@ 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 e8135f41a1c24dd7bba73693983552635ed24f74..023ac6d5fa864762a815a6f18d23314221695cb0 100644 (file)
--- 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 219904363737a73de69b603bd8b89cfa2a061398..80286076a111a4f195a6721f15427ba48147630b 100644 (file)
--- 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/regress/pg_regress.c b/src/test/regress/pg_regress.c
index 61c035a39834a81dfb08e88a283f4eae8101a533..efc41fca2ba791535ec41f436b670ac353499456 100644 (file)
--- 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 695e0a0d6ec9e93cda7b8d97f97658f2a7ae085a..ff05646c90e0960cc79ade71a04744c791a7dcee 100644 (file)
--- 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