Add resource statistics reporting to ANALYZE VERBOSE.

Previously, log_autovacuum_min_duration utilized dedicated code for
logging resource statistics, such as system and buffer usage during
autoanalyze. However, this logging functionality was not utilized by
ANALYZE VERBOSE.

This commit adds resource statistics reporting to ANALYZE VERBOSE by
reusing the same logging code as autoanalyze.

Author: Anthonin Bonnefoy
Reviewed-by: Masahiko Sawada
Discussion: https://postgr.es/m/CAO6_Xqr__kTTCLkftqS0qSCm-J7_xbRG3Ge2rWhucxQJMJhcRA%40mail.gmail.com

diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index 501592322182adf8d8f225bb65ef59b1d64cd30e..902eb1a450863eb5bd8b77f2a49e1b2b6a36d681 100644 (file)
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -288,7 +288,9 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
                ind;
    Relation   *Irel;
    int         nindexes;
-   bool        hasindex;
+   bool        verbose,
+               instrument,
+               hasindex;
    VacAttrStats **vacattrstats;
    AnlIndexData *indexdata;
    int         targrows,
@@ -308,6 +310,9 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
    PgStat_Counter startreadtime = 0;
    PgStat_Counter startwritetime = 0;
 
+   verbose = (params->options & VACOPT_VERBOSE) != 0;
+   instrument = (verbose || (AmAutoVacuumWorkerProcess() &&
+                             params->log_min_duration >= 0));
    if (inh)
        ereport(elevel,
                (errmsg("analyzing \"%s.%s\" inheritance tree",
@@ -339,8 +344,11 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
    save_nestlevel = NewGUCNestLevel();
    RestrictSearchPath();
 
-   /* measure elapsed time iff autovacuum logging requires it */
-   if (AmAutoVacuumWorkerProcess() && params->log_min_duration >= 0)
+   /*
+    * measure elapsed time if called with verbose or if autovacuum logging
+    * requires it
+    */
+   if (instrument)
    {
        if (track_io_timing)
        {
@@ -723,17 +731,18 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
    vac_close_indexes(nindexes, Irel, NoLock);
 
    /* Log the action if appropriate */
-   if (AmAutoVacuumWorkerProcess() && params->log_min_duration >= 0)
+   if (instrument)
    {
        TimestampTz endtime = GetCurrentTimestamp();
 
-       if (params->log_min_duration == 0 ||
+       if (verbose || params->log_min_duration == 0 ||
            TimestampDifferenceExceeds(starttime, endtime,
                                       params->log_min_duration))
        {
            long        delay_in_ms;
            double      read_rate = 0;
            double      write_rate = 0;
+           char       *msgfmt;
            StringInfoData buf;
            int64       total_blks_hit;
            int64       total_blks_read;
@@ -785,7 +794,13 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
             */
 
            initStringInfo(&buf);
-           appendStringInfo(&buf, _("automatic analyze of table \"%s.%s.%s\"\n"),
+
+           if (AmAutoVacuumWorkerProcess())
+               msgfmt = _("automatic analyze of table \"%s.%s.%s\"\n");
+           else
+               msgfmt = _("finished analyzing table \"%s.%s.%s\"\n");
+
+           appendStringInfo(&buf, msgfmt,
                             get_database_name(MyDatabaseId),
                             get_namespace_name(RelationGetNamespace(onerel)),
                             RelationGetRelationName(onerel));
@@ -805,7 +820,7 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
                             (long long) total_blks_dirtied);
            appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
 
-           ereport(LOG,
+           ereport(verbose ? INFO : LOG,
                    (errmsg_internal("%s", buf.data)));
 
            pfree(buf.data);